Re: max-cache-size doesn't work with 9.5.0b1

classic Classic list List threaded Threaded
24 messages Options
12
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Nagy, Attila
On 2008.01.28. 19:21, JINMEI Tatuya / 神明達哉 wrote:

> At Mon, 28 Jan 2008 17:10:28 +0100,
> Attila Nagy <[hidden email]> wrote:
>
>  
>>> If you have time, could you rebuild named as follows
>>>
>>> % STD_CDEFINES='-DLRU_DEBUG' ./configure; make
>>>
>>> and try again?  This won't solve the problem, but provide more
>>> detailed log messages tracking the memory usage of the cache.  Make
>>> sure threads are disabled (this debug feature is currently
>>> thread-unsafe and trigger an assertion failure when used with multiple
>>> threads).
>>>  
>>>      
>> Without threading I don't see this effect, the memory usage stops at a
>> sane limit and it's size can be affected by setting the max-cache-size
>> option.
>>
>> I don't think you would gain anything usable with that, am I right?
>>    
>
> Right.  Can you try a simpler patch that focuses on the memory usage
> status and works with threads?  If so, I'll write one and send it to
> you.
>  
Of course. The machines are diskless, so writing larger log files
directly is not an easy task. (syslog is ok)

Thanks.

ps: I have an other problem. I've recently switched from a last year
6-STABLE to 7-STABLE and got pretty bad results on the same machine with
the same bind (9.4).
The graphs are here:
http://picasaweb.google.com/nagy.attila/20080129Fbsd6vs7Bind

The interesting part (from when the comments are valid) starts at around
the half of the picture. You can see that on FreeBSD 6, the CPU load is
pretty much good, but on 7, both the userspace and the kernelspace
activity grows significantly.
I've used libthr on 6, and it is the default on 7 too. bind is threaded.
I use ISC_INTERNAL_MALLOC, but the effect is the same without it.

I've cc-ed the freebsd-performance, I guess there are several other ppl,
who is interested in bind performance on this OS.
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

JINMEI Tatuya / 神明達哉-3
At Tue, 29 Jan 2008 11:40:39 +0100,
Attila Nagy <[hidden email]> wrote:

> >> Without threading I don't see this effect, the memory usage stops at a
> >> sane limit and it's size can be affected by setting the max-cache-size
> >> option.
> >>
> >> I don't think you would gain anything usable with that, am I right?
> >
> > Right.  Can you try a simpler patch that focuses on the memory usage
> > status and works with threads?  If so, I'll write one and send it to
> > you.
> >  
> Of course. The machines are diskless, so writing larger log files
> directly is not an easy task. (syslog is ok)
Okay, please use the attached patch (applicable to 9.5.0b1, and also
to 9.5.0b2 when it's published).  Build it with:
% STD_CDEFINES='-DLRU_DEBUG2=2' ./configure --enable-threads
(or set STD_CDEFINES using setenv if you use a csh variant)

The log messages shouldn't be very noisy, but if you find them too
frequent, rebuild it with:
% STD_CDEFINES='-DLRU_DEBUG2=1' ./configure --enable-threads

Note that, if this is a thread-related bug, it may not always be
reproduceable; please try several times if the problem doesn't seem to
happen.  (BTW: did it always occur when you first found the problem?)

> ps: I have an other problem. I've recently switched from a last year
> 6-STABLE to 7-STABLE and got pretty bad results on the same machine with
> the same bind (9.4).
> The graphs are here:
> http://picasaweb.google.com/nagy.attila/20080129Fbsd6vs7Bind
>
> The interesting part (from when the comments are valid) starts at around
> the half of the picture. You can see that on FreeBSD 6, the CPU load is
> pretty much good, but on 7, both the userspace and the kernelspace
> activity grows significantly.
I have no idea about why this happened at the moment.  Do both server
handle the same level of query rate?  (I'm also curious what happened
in the first half of the graphs for both cases).

> I've used libthr on 6, and it is the default on 7 too. bind is threaded.
> I use ISC_INTERNAL_MALLOC, but the effect is the same without it.

This shouldn't matter because ISC_INTERNAL_MALLOC is enabled by
default as of 9.4.

Thanks,

---
JINMEI, Tatuya
Internet Systems Consortium, Inc.


_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Nagy, Attila
On 2008.01.30. 3:28, JINMEI Tatuya / 神明達哉 wrote:

> At Tue, 29 Jan 2008 11:40:39 +0100,
> Attila Nagy <[hidden email]> wrote:
>
>  
>>>> Without threading I don't see this effect, the memory usage stops at a
>>>> sane limit and it's size can be affected by setting the max-cache-size
>>>> option.
>>>>
>>>> I don't think you would gain anything usable with that, am I right?
>>>>        
>>> Right.  Can you try a simpler patch that focuses on the memory usage
>>> status and works with threads?  If so, I'll write one and send it to
>>> you.
>>>  
>>>      
>> Of course. The machines are diskless, so writing larger log files
>> directly is not an easy task. (syslog is ok)
>>    
>
> Okay, please use the attached patch (applicable to 9.5.0b1, and also
> to 9.5.0b2 when it's published).  Build it with:
> % STD_CDEFINES='-DLRU_DEBUG2=2' ./configure --enable-threads
> (or set STD_CDEFINES using setenv if you use a csh variant)
>  
Will try, thanks.

>> ps: I have an other problem. I've recently switched from a last year
>> 6-STABLE to 7-STABLE and got pretty bad results on the same machine with
>> the same bind (9.4).
>> The graphs are here:
>> http://picasaweb.google.com/nagy.attila/20080129Fbsd6vs7Bind
>>
>> The interesting part (from when the comments are valid) starts at around
>> the half of the picture. You can see that on FreeBSD 6, the CPU load is
>> pretty much good, but on 7, both the userspace and the kernelspace
>> activity grows significantly.
>>    
>
> I have no idea about why this happened at the moment.  Do both server
> handle the same level of query rate?  (I'm also curious what happened
> in the first half of the graphs for both cases).
>  
Exactly the same (a per packet load balancer is in front of them). Even
the machines are the same. I've replaced the pictures, the previous ones
included some unintended reboot-n-try stuff.
>  
>> I've used libthr on 6, and it is the default on 7 too. bind is threaded.
>> I use ISC_INTERNAL_MALLOC, but the effect is the same without it.
>>    
>
> This shouldn't matter because ISC_INTERNAL_MALLOC is enabled by
> default as of 9.4.
>  
Ouch, I didn't know this. Thanks for the clarification.
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Nagy, Attila
In reply to this post by JINMEI Tatuya / 神明達哉-3
On 2008.01.30. 3:28, JINMEI Tatuya / 神明達哉 wrote:

> Okay, please use the attached patch (applicable to 9.5.0b1, and also
> to 9.5.0b2 when it's published).  Build it with:
> % STD_CDEFINES='-DLRU_DEBUG2=2' ./configure --enable-threads
> (or set STD_CDEFINES using setenv if you use a csh variant)
>
> The log messages shouldn't be very noisy, but if you find them too
> frequent, rebuild it with:
> % STD_CDEFINES='-DLRU_DEBUG2=1' ./configure --enable-threads
>
> Note that, if this is a thread-related bug, it may not always be
> reproduceable; please try several times if the problem doesn't seem to
> happen.  (BTW: did it always occur when you first found the problem?)
>  
Yes, if bind was built with threads, the memory usage always grew behind
max-cache-size very quickly.

Here is the log:
http://people.fsn.hu/~bra/freebsd/bind950-memory-20080203/bind950b1
the memory usage (RSS, reported by top) in megabytes:
19:10:37 466
19:11:20 522
19:11:53 566
19:13:06 666
19:14:17 766

max-cache-size was set to 64M.

_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Mark Andrews

> On 2008.01.30. 3:28, JINMEI Tatuya / 神明達哉 wrote:
> > Okay, please use the attached patch (applicable to 9.5.0b1, and also
> > to 9.5.0b2 when it's published).  Build it with:
> > % STD_CDEFINES='-DLRU_DEBUG2=2' ./configure --enable-threads
> > (or set STD_CDEFINES using setenv if you use a csh variant)
> >
> > The log messages shouldn't be very noisy, but if you find them too
> > frequent, rebuild it with:
> > % STD_CDEFINES='-DLRU_DEBUG2=1' ./configure --enable-threads
> >
> > Note that, if this is a thread-related bug, it may not always be
> > reproduceable; please try several times if the problem doesn't seem to
> > happen.  (BTW: did it always occur when you first found the problem?)
> >  
> Yes, if bind was built with threads, the memory usage always grew behind
> max-cache-size very quickly.
>
> Here is the log:
> http://people.fsn.hu/~bra/freebsd/bind950-memory-20080203/bind950b1
> the memory usage (RSS, reported by top) in megabytes:
> 19:10:37 466
> 19:11:20 522
> 19:11:53 566
> 19:13:06 666
> 19:14:17 766
>
> max-cache-size was set to 64M.
 
        Please try this patch.

        Mark
 
Index: lib/dns/cache.c
===================================================================
RCS file: /proj/cvs/prod/bind9/lib/dns/cache.c,v
retrieving revision 1.76
diff -u -r1.76 cache.c
--- lib/dns/cache.c 19 Oct 2007 17:15:53 -0000 1.76
+++ lib/dns/cache.c 3 Feb 2008 23:59:46 -0000
@@ -708,8 +708,11 @@
 
         LOCK(&cache->cleaner.lock);
 
-        dns_db_overmem(cache->db, overmem);
-        cache->cleaner.overmem = overmem;
+ if (overmem != cache->cleaner.overmem) {
+ dns_db_overmem(cache->db, overmem);
+ cache->cleaner.overmem = overmem;
+ isc_mem_water(cache->mctx, mark);
+ }
 
         UNLOCK(&cache->cleaner.lock);
 }
Index: lib/isc/mem.c
===================================================================
RCS file: /proj/cvs/prod/bind9/lib/isc/mem.c,v
retrieving revision 1.140
diff -u -r1.140 mem.c
--- lib/isc/mem.c 18 Jan 2008 23:46:58 -0000 1.140
+++ lib/isc/mem.c 3 Feb 2008 23:59:48 -0000
@@ -1086,7 +1086,6 @@
  ADD_TRACE(ctx, ptr, size, file, line);
  if (ctx->hi_water != 0U && !ctx->hi_called &&
     ctx->inuse > ctx->hi_water) {
- ctx->hi_called = ISC_TRUE;
  call_water = ISC_TRUE;
  }
  if (ctx->inuse > ctx->maxinuse) {
@@ -1144,8 +1143,6 @@
  */
  if (ctx->hi_called &&
     (ctx->inuse < ctx->lo_water || ctx->lo_water == 0U)) {
- ctx->hi_called = ISC_FALSE;
-
  if (ctx->water != NULL)
  call_water = ISC_TRUE;
  }
@@ -1155,6 +1152,18 @@
  (ctx->water)(ctx->water_arg, ISC_MEM_LOWATER);
 }
 
+void
+isc_mem_water(isc_mem_t *ctx, int flag) {
+ REQUIRE(VALID_CONTEXT(ctx));
+
+ MCTXLOCK(ctx, &ctx->lock);
+ if (flag == ISC_MEM_LOWATER)
+ ctx->hi_called = ISC_FALSE;
+ else if (flag == ISC_MEM_HIWATER)
+ ctx->hi_called = ISC_TRUE;
+ MCTXUNLOCK(ctx, &ctx->lock);
+}
+
 #if ISC_MEM_TRACKLINES
 static void
 print_active(isc_mem_t *mctx, FILE *out) {
--
Mark Andrews, ISC
1 Seymour St., Dundas Valley, NSW 2117, Australia
PHONE: +61 2 9871 4742                 INTERNET: [hidden email]
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Mark Andrews

>  
> Please try this patch.
>
> Mark

        Revised.

Index: lib/isc/mem.c
===================================================================
RCS file: /proj/cvs/prod/bind9/lib/isc/mem.c,v
retrieving revision 1.140
diff -u -r1.140 mem.c
--- lib/isc/mem.c 18 Jan 2008 23:46:58 -0000 1.140
+++ lib/isc/mem.c 4 Feb 2008 00:29:44 -0000
@@ -1086,7 +1086,6 @@
  ADD_TRACE(ctx, ptr, size, file, line);
  if (ctx->hi_water != 0U && !ctx->hi_called &&
     ctx->inuse > ctx->hi_water) {
- ctx->hi_called = ISC_TRUE;
  call_water = ISC_TRUE;
  }
  if (ctx->inuse > ctx->maxinuse) {
@@ -1144,8 +1143,6 @@
  */
  if (ctx->hi_called &&
     (ctx->inuse < ctx->lo_water || ctx->lo_water == 0U)) {
- ctx->hi_called = ISC_FALSE;
-
  if (ctx->water != NULL)
  call_water = ISC_TRUE;
  }
@@ -1155,6 +1152,18 @@
  (ctx->water)(ctx->water_arg, ISC_MEM_LOWATER);
 }
 
+void
+isc_mem_water(isc_mem_t *ctx, int flag) {
+ REQUIRE(VALID_CONTEXT(ctx));
+
+ MCTXLOCK(ctx, &ctx->lock);
+ if (flag == ISC_MEM_LOWATER)
+ ctx->hi_called = ISC_FALSE;
+ else if (flag == ISC_MEM_HIWATER)
+ ctx->hi_called = ISC_TRUE;
+ MCTXUNLOCK(ctx, &ctx->lock);
+}
+
 #if ISC_MEM_TRACKLINES
 static void
 print_active(isc_mem_t *mctx, FILE *out) {
Index: lib/dns/acache.c
===================================================================
RCS file: /proj/cvs/prod/bind9/lib/dns/acache.c,v
retrieving revision 1.20
diff -u -r1.20 acache.c
--- lib/dns/acache.c 19 Jun 2007 23:47:16 -0000 1.20
+++ lib/dns/acache.c 4 Feb 2008 00:29:46 -0000
@@ -965,10 +965,14 @@
 
  LOCK(&acache->cleaner.lock);
 
- acache->cleaner.overmem = overmem;
+ if (acache->cleaner.overmem != overmem) {
+ acache->cleaner.overmem = overmem;
 
- if (acache->cleaner.overmem_event != NULL)
- isc_task_send(acache->task, &acache->cleaner.overmem_event);
+ if (acache->cleaner.overmem_event != NULL)
+ isc_task_send(acache->task,
+      &acache->cleaner.overmem_event);
+ isc_mem_water(acache->mctx, mark);
+ }
 
  UNLOCK(&acache->cleaner.lock);
 }
Index: lib/dns/adb.c
===================================================================
RCS file: /proj/cvs/prod/bind9/lib/dns/adb.c,v
retrieving revision 1.233
diff -u -r1.233 adb.c
--- lib/dns/adb.c 19 Oct 2007 17:15:53 -0000 1.233
+++ lib/dns/adb.c 4 Feb 2008 00:29:50 -0000
@@ -128,6 +128,7 @@
 
         isc_mutex_t                     lock;
         isc_mutex_t                     reflock; /*%< Covers irefcnt, erefcnt */
+        isc_mutex_t                     overmemlock; /*%< Covers overmem */
         isc_mem_t                      *mctx;
         dns_view_t                     *view;
         isc_timermgr_t                 *timermgr;
@@ -2138,6 +2139,7 @@
         DESTROYLOCK(&adb->reflock);
         DESTROYLOCK(&adb->lock);
         DESTROYLOCK(&adb->mplock);
+        DESTROYLOCK(&adb->overmemlock);
 
         isc_mem_putanddetach(&adb->mctx, adb, sizeof(dns_adb_t));
 }
@@ -2225,6 +2227,10 @@
         if (result != ISC_R_SUCCESS)
                 goto fail0d;
 
+        result = isc_mutex_init(&adb->overmemlock);
+        if (result != ISC_R_SUCCESS)
+                goto fail0e;
+
         /*
          * Initialize the bucket locks for names and elements.
          * May as well initialize the list heads, too.
@@ -2343,6 +2349,8 @@
         if (adb->afmp != NULL)
                 isc_mempool_destroy(&adb->afmp);
 
+        DESTROYLOCK(&adb->overmemlock);
+ fail0e:
         DESTROYLOCK(&adb->reflock);
  fail0d:
         DESTROYLOCK(&adb->mplock);
@@ -3782,16 +3790,21 @@
         DP(ISC_LOG_DEBUG(1),
            "adb reached %s water mark", overmem ? "high" : "low");
 
-        adb->overmem = overmem;
+ LOCK(&adb->overmemlock);
+ if (adb->overmem != overmem) {
+ adb->overmem = overmem;
 #if 0       /* we don't need this timer for the new cleaning policy. */
-        if (overmem) {
-                isc_interval_t interval;
+ if (overmem) {
+ isc_interval_t interval;
 
-                isc_interval_set(&interval, 0, 1);
-                (void)isc_timer_reset(adb->timer, isc_timertype_once, NULL,
-                                      &interval, ISC_TRUE);
-        }
-#endif
+ isc_interval_set(&interval, 0, 1);
+ (void)isc_timer_reset(adb->timer, isc_timertype_once,
+      NULL, &interval, ISC_TRUE);
+ }
+#endif
+ isc_mem_water(adb->mctx, mark);
+ }
+ UNLOCK(&adb->overmemlock);
 }
 
 void
Index: lib/dns/cache.c
===================================================================
RCS file: /proj/cvs/prod/bind9/lib/dns/cache.c,v
retrieving revision 1.76
diff -u -r1.76 cache.c
--- lib/dns/cache.c 19 Oct 2007 17:15:53 -0000 1.76
+++ lib/dns/cache.c 4 Feb 2008 00:29:51 -0000
@@ -708,8 +708,11 @@
 
         LOCK(&cache->cleaner.lock);
 
-        dns_db_overmem(cache->db, overmem);
-        cache->cleaner.overmem = overmem;
+ if (overmem != cache->cleaner.overmem) {
+ dns_db_overmem(cache->db, overmem);
+ cache->cleaner.overmem = overmem;
+ isc_mem_water(cache->mctx, mark);
+ }
 
         UNLOCK(&cache->cleaner.lock);
 }
--
Mark Andrews, ISC
1 Seymour St., Dundas Valley, NSW 2117, Australia
PHONE: +61 2 9871 4742                 INTERNET: [hidden email]
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

JINMEI Tatuya / 神明達哉-3
In reply to this post by Nagy, Attila
At Sun, 03 Feb 2008 20:24:25 +0100,
Attila Nagy <[hidden email]> wrote:

> Yes, if bind was built with threads, the memory usage always grew behind
> max-cache-size very quickly.
>
> Here is the log:
> http://people.fsn.hu/~bra/freebsd/bind950-memory-20080203/bind950b1
> the memory usage (RSS, reported by top) in megabytes:
> 19:10:37 466
> 19:11:20 522
> 19:11:53 566
> 19:13:06 666
> 19:14:17 766
>
> max-cache-size was set to 64M.

Hmm.  According to the log message, named seems to control the cache
memory pretty well so that it doesn't exceed max-cache-size.  So, the
memory hog should be somewhere else.

One obvious explanation is memory leak, of course.  If it occurs
within named, you should be able to find it by stopping the daemon
(memory leak will trigger assertion failure).

Another possible scenario is that you're being hit by known memory
leak in the built-in statistics HTTP server (unfortunately, this isn't
caught by assertion).  If you've enabled the feature and are
retrieving statistics via HTTP at a very high rate, your server will
possibly eat memory avariciously.  I actually suspect that this is NOT
the likely cause in this case, from the very rapid growth you showed,
but if you enable the built-in HTTP server, could you turn it off and
try again?  BTW, this leak will be fixed in 9.5.0b2.

Finally, at the risk of pointing a finger at someone else who's
innocent, is it possible that there's leak in FreeBSD's thread
library?  For example, busy BIND9 caching servers frequently create
and destroy mutex locks; if the thread library fails to cleanly free
memory for mutex's, the server memory will grow rapidly.

p.s. I'm afraid the patch Mark provided in his response won't solve
this particular problem from the information we've got so far.

---
JINMEI, Tatuya
Internet Systems Consortium, Inc.
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Nagy, Attila
On 2008.02.04. 20:36, JINMEI Tatuya / 神明達哉 wrote:

> At Sun, 03 Feb 2008 20:24:25 +0100,
> Attila Nagy <[hidden email]> wrote:
>
>  
>> Yes, if bind was built with threads, the memory usage always grew behind
>> max-cache-size very quickly.
>>
>> Here is the log:
>> http://people.fsn.hu/~bra/freebsd/bind950-memory-20080203/bind950b1
>> the memory usage (RSS, reported by top) in megabytes:
>> 19:10:37 466
>> 19:11:20 522
>> 19:11:53 566
>> 19:13:06 666
>> 19:14:17 766
>>
>> max-cache-size was set to 64M.
>>    
>
> Hmm.  According to the log message, named seems to control the cache
> memory pretty well so that it doesn't exceed max-cache-size.  So, the
> memory hog should be somewhere else.
>
> One obvious explanation is memory leak, of course.  If it occurs
> within named, you should be able to find it by stopping the daemon
> (memory leak will trigger assertion failure).
>
> Another possible scenario is that you're being hit by known memory
> leak in the built-in statistics HTTP server (unfortunately, this isn't
> caught by assertion).  If you've enabled the feature and are
> retrieving statistics via HTTP at a very high rate, your server will
> possibly eat memory avariciously.  I actually suspect that this is NOT
> the likely cause in this case, from the very rapid growth you showed,
> but if you enable the built-in HTTP server, could you turn it off and
> try again?  BTW, this leak will be fixed in 9.5.0b2.
>  
I didn't even look after how could I enable the built-in HTTP server, so
if it's not on by default, I haven't had it.

> Finally, at the risk of pointing a finger at someone else who's
> innocent, is it possible that there's leak in FreeBSD's thread
> library?  For example, busy BIND9 caching servers frequently create
> and destroy mutex locks; if the thread library fails to cleanly free
> memory for mutex's, the server memory will grow rapidly.
>  
Bind 9.4.2 works fine on the same machine (threaded), if that counts.

> p.s. I'm afraid the patch Mark provided in his response won't solve
> this particular problem from the information we've got so far.
>  
I will try it nevertheless.
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Nagy, Attila
In reply to this post by Mark Andrews
On 02/04/08 01:31, Mark Andrews wrote:

>>  
>> Please try this patch.
>>
>> Mark
>>    
>
> Revised.
>
> Index: lib/isc/mem.c
> ===================================================================
> RCS file: /proj/cvs/prod/bind9/lib/isc/mem.c,v
> retrieving revision 1.140
> diff -u -r1.140 mem.c
> --- lib/isc/mem.c 18 Jan 2008 23:46:58 -0000 1.140
> +++ lib/isc/mem.c 4 Feb 2008 00:29:44 -0000
> @@ -1086,7 +1086,6 @@
>   ADD_TRACE(ctx, ptr, size, file, line);
>   if (ctx->hi_water != 0U && !ctx->hi_called &&
>      ctx->inuse > ctx->hi_water) {
> - ctx->hi_called = ISC_TRUE;
>   call_water = ISC_TRUE;
>   }
>   if (ctx->inuse > ctx->maxinuse) {
> @@ -1144,8 +1143,6 @@
>   */
>   if (ctx->hi_called &&
>      (ctx->inuse < ctx->lo_water || ctx->lo_water == 0U)) {
> - ctx->hi_called = ISC_FALSE;
> -
>   if (ctx->water != NULL)
>   call_water = ISC_TRUE;
>   }
> @@ -1155,6 +1152,18 @@
>   (ctx->water)(ctx->water_arg, ISC_MEM_LOWATER);
>  }
>  
> +void
> +isc_mem_water(isc_mem_t *ctx, int flag) {
> + REQUIRE(VALID_CONTEXT(ctx));
> +
> + MCTXLOCK(ctx, &ctx->lock);
> + if (flag == ISC_MEM_LOWATER)
> + ctx->hi_called = ISC_FALSE;
> + else if (flag == ISC_MEM_HIWATER)
> + ctx->hi_called = ISC_TRUE;
> + MCTXUNLOCK(ctx, &ctx->lock);
> +}
> +
>  #if ISC_MEM_TRACKLINES
>  static void
>  print_active(isc_mem_t *mctx, FILE *out) {
> Index: lib/dns/acache.c
> ===================================================================
> RCS file: /proj/cvs/prod/bind9/lib/dns/acache.c,v
> retrieving revision 1.20
> diff -u -r1.20 acache.c
> --- lib/dns/acache.c 19 Jun 2007 23:47:16 -0000 1.20
> +++ lib/dns/acache.c 4 Feb 2008 00:29:46 -0000
> @@ -965,10 +965,14 @@
>  
>   LOCK(&acache->cleaner.lock);
>  
> - acache->cleaner.overmem = overmem;
> + if (acache->cleaner.overmem != overmem) {
> + acache->cleaner.overmem = overmem;
>  
> - if (acache->cleaner.overmem_event != NULL)
> - isc_task_send(acache->task, &acache->cleaner.overmem_event);
> + if (acache->cleaner.overmem_event != NULL)
> + isc_task_send(acache->task,
> +      &acache->cleaner.overmem_event);
> + isc_mem_water(acache->mctx, mark);
> + }
>  
>   UNLOCK(&acache->cleaner.lock);
>  }
> Index: lib/dns/adb.c
> ===================================================================
> RCS file: /proj/cvs/prod/bind9/lib/dns/adb.c,v
> retrieving revision 1.233
> diff -u -r1.233 adb.c
> --- lib/dns/adb.c 19 Oct 2007 17:15:53 -0000 1.233
> +++ lib/dns/adb.c 4 Feb 2008 00:29:50 -0000
> @@ -128,6 +128,7 @@
>  
>          isc_mutex_t                     lock;
>          isc_mutex_t                     reflock; /*%< Covers irefcnt, erefcnt */
> +        isc_mutex_t                     overmemlock; /*%< Covers overmem */
>          isc_mem_t                      *mctx;
>          dns_view_t                     *view;
>          isc_timermgr_t                 *timermgr;
> @@ -2138,6 +2139,7 @@
>          DESTROYLOCK(&adb->reflock);
>          DESTROYLOCK(&adb->lock);
>          DESTROYLOCK(&adb->mplock);
> +        DESTROYLOCK(&adb->overmemlock);
>  
>          isc_mem_putanddetach(&adb->mctx, adb, sizeof(dns_adb_t));
>  }
> @@ -2225,6 +2227,10 @@
>          if (result != ISC_R_SUCCESS)
>                  goto fail0d;
>  
> +        result = isc_mutex_init(&adb->overmemlock);
> +        if (result != ISC_R_SUCCESS)
> +                goto fail0e;
> +
>          /*
>           * Initialize the bucket locks for names and elements.
>           * May as well initialize the list heads, too.
> @@ -2343,6 +2349,8 @@
>          if (adb->afmp != NULL)
>                  isc_mempool_destroy(&adb->afmp);
>  
> +        DESTROYLOCK(&adb->overmemlock);
> + fail0e:
>          DESTROYLOCK(&adb->reflock);
>   fail0d:
>          DESTROYLOCK(&adb->mplock);
> @@ -3782,16 +3790,21 @@
>          DP(ISC_LOG_DEBUG(1),
>             "adb reached %s water mark", overmem ? "high" : "low");
>  
> -        adb->overmem = overmem;
> + LOCK(&adb->overmemlock);
> + if (adb->overmem != overmem) {
> + adb->overmem = overmem;
>  #if 0       /* we don't need this timer for the new cleaning policy. */
> -        if (overmem) {
> -                isc_interval_t interval;
> + if (overmem) {
> + isc_interval_t interval;
>  
> -                isc_interval_set(&interval, 0, 1);
> -                (void)isc_timer_reset(adb->timer, isc_timertype_once, NULL,
> -                                      &interval, ISC_TRUE);
> -        }
> -#endif
> + isc_interval_set(&interval, 0, 1);
> + (void)isc_timer_reset(adb->timer, isc_timertype_once,
> +      NULL, &interval, ISC_TRUE);
> + }
> +#endif
> + isc_mem_water(adb->mctx, mark);
> + }
> + UNLOCK(&adb->overmemlock);
>  }
>  
>  void
> Index: lib/dns/cache.c
> ===================================================================
> RCS file: /proj/cvs/prod/bind9/lib/dns/cache.c,v
> retrieving revision 1.76
> diff -u -r1.76 cache.c
> --- lib/dns/cache.c 19 Oct 2007 17:15:53 -0000 1.76
> +++ lib/dns/cache.c 4 Feb 2008 00:29:51 -0000
> @@ -708,8 +708,11 @@
>  
>          LOCK(&cache->cleaner.lock);
>  
> -        dns_db_overmem(cache->db, overmem);
> -        cache->cleaner.overmem = overmem;
> + if (overmem != cache->cleaner.overmem) {
> + dns_db_overmem(cache->db, overmem);
> + cache->cleaner.overmem = overmem;
> + isc_mem_water(cache->mctx, mark);
> + }
>  
>          UNLOCK(&cache->cleaner.lock);
>  }
>  
Sorry about the long delay...

With this patch, the memory usage still grows well beyond the set limit
(32M in this case, 380M resident usage after about 10 minutes of running).

Applied to b2.

--
Attila Nagy                                   e-mail: [hidden email]
Free Software Network (FSN.HU)                 phone: +3630 306 6758
http://www.fsn.hu/

_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Nagy, Attila
In reply to this post by Nagy, Attila
On 02/06/08 04:57, JINMEI Tatuya / 神明達哉 wrote:
> One other usual suspect is BIND9's "acache" if you enable it and the
> server also acts as a (busy) authoritative server.  Is this the case
> for you?  (But again, it should also cause the same problem for 9.4.2,
> so I don't think this is the reason, either)
>  
No, this is a caching only nameserver (but have some RFC1918 reverse
zones defined as empty to overcome problems with IANA's blackhole servers).

> Then named will listen on [your_ip_address]:some_port, and you can
> browse internal statistics by accessing
> http://[your_ip_address]:some_port with your browser.  When you notice
> the memory starts growing, retrieving the information several times,
> and compare the "Memory" section at the end of the page.  If the
> memory hog is inside named, there should be significant growth in some
> of the rows accordingly.
>  
Here are the results:
http://people.fsn.hu/~bra/freebsd/bind950-memory-20080212/
and at the end, the relevant line from top.

Is this FreeBSD leaking then?

--
Attila Nagy                                   e-mail: [hidden email]
Free Software Network (FSN.HU)                 phone: +3630 306 6758
http://www.fsn.hu/

_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Nagy, Attila
On 02/12/08 18:55, JINMEI Tatuya / 神明達哉 wrote:

> At Tue, 12 Feb 2008 18:10:12 +0100,
> Attila Nagy <[hidden email]> wrote:
>
>  
>>> Then named will listen on [your_ip_address]:some_port, and you can
>>> browse internal statistics by accessing
>>> http://[your_ip_address]:some_port with your browser.  When you notice
>>> the memory starts growing, retrieving the information several times,
>>> and compare the "Memory" section at the end of the page.  If the
>>> memory hog is inside named, there should be significant growth in some
>>> of the rows accordingly.
>>>  
>>>      
>> Here are the results:
>> http://people.fsn.hu/~bra/freebsd/bind950-memory-20080212/
>> and at the end, the relevant line from top.
>>
>> Is this FreeBSD leaking then?
>>    
>
> Looking at the last stat
> http://people.fsn.hu/~bra/freebsd/bind950-memory-20080212/bind4
> even the total of "MaxUse" is about 69MB, while the ps output
> indicates the resident size is 441MB.  So, yes, there should be
> something odd not directly related to the named's (normal) behavior.
>
> Can you try the same test with only one worker thread (by using the
> '-n 1' command line option)?  Then we may be able to chase the problem
> further.
>  
Of course. See the bindn1 files at the same location. (only the memory
section included)
The effect is pretty much the same.

--
Attila Nagy                                   e-mail: [hidden email]
Free Software Network (FSN.HU)                 phone: +3630 306 6758
http://www.fsn.hu/

_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

JINMEI Tatuya / 神明達哉-3
At Wed, 13 Feb 2008 13:06:58 +0100,
Attila Nagy <[hidden email]> wrote:

> Of course. See the bindn1 files at the same location. (only the memory
> section included)
> The effect is pretty much the same.

Okay, then please try this patch with '-n 1' (note: this patch doesn't
contain the memory statistics hack via the HTTP interface, but I don't
we don't need it for this test).

---
JINMEI, Tatuya
Internet Systems Consortium, Inc.


_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"

bind-9.5.patch (14K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Nagy, Attila
On 02/13/08 21:44,  wrote:
> Okay, then please try this patch with '-n 1' (note: this patch doesn't
> contain the memory statistics hack via the HTTP interface, but I don't
> we don't need it for this test).
>
>  
Sorry for the delay, here are the logs:
Feb 19 13:51:29 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3679584
Feb 19 13:51:30 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3145608
Feb 19 13:51:30 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670040
Feb 19 13:51:31 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3142784
Feb 19 13:51:31 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670960
Feb 19 13:51:32 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3142568
Feb 19 13:51:33 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3699168
Feb 19 13:51:35 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3143144
Feb 19 13:51:35 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3671088
Feb 19 13:51:37 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3141408
Feb 19 13:51:37 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3672184
Feb 19 13:51:38 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3137912
Feb 19 13:51:40 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670160
Feb 19 13:51:41 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3145440
Feb 19 13:51:41 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3680224
Feb 19 13:51:42 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3145528
Feb 19 13:51:43 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3674320
Feb 19 13:51:45 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3145696
Feb 19 13:51:46 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3675800
Feb 19 13:51:48 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3142104
Feb 19 13:51:48 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3674800
Feb 19 13:51:50 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3144104
Feb 19 13:51:50 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670504
Feb 19 13:51:51 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3145584
Feb 19 13:51:52 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670200
Feb 19 13:51:54 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3145496
Feb 19 13:51:55 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3687768
Feb 19 13:51:57 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 3188272, overmem=1
Feb 19 13:51:57 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:51:57 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3141232
Feb 19 13:51:58 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670632
Feb 19 13:51:59 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3144408
Feb 19 13:52:00 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670704
Feb 19 13:52:01 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3684296
Feb 19 13:52:03 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3144712
Feb 19 13:52:03 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670112
Feb 19 13:52:04 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3145712
Feb 19 13:52:05 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3671232
Feb 19 13:52:07 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3145584
Feb 19 13:52:08 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3697744
Feb 19 13:52:09 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3144664
Feb 19 13:52:10 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670040
Feb 19 13:52:13 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3142976
Feb 19 13:52:13 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3670592
Feb 19 13:52:16 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to FALSE, mem inuse 3142792
Feb 19 13:52:16 cns00a named[45171]: database: info: ADB 0x800f16000:
overmem switch to TRUE, mem inuse 3672720
Feb 19 13:52:27 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 3651072, overmem=1
Feb 19 13:52:27 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:52:57 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 6832056, overmem=1
Feb 19 13:52:57 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:53:27 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 6331216, overmem=1
Feb 19 13:53:27 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:53:57 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 7005632, overmem=1
Feb 19 13:53:57 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:54:27 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 5024232, overmem=1
Feb 19 13:54:27 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:54:57 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 6819600, overmem=1
Feb 19 13:54:57 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:55:27 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 6863768, overmem=1
Feb 19 13:55:27 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:55:57 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 7097880, overmem=1
Feb 19 13:55:57 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:56:27 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 5771000, overmem=1
Feb 19 13:56:27 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:56:57 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 7198400, overmem=1
Feb 19 13:56:57 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
Feb 19 13:57:27 cns00a named[45171]: database: info: ADB memory usage
0x800f16000: mem inuse 7568776, overmem=1
Feb 19 13:57:27 cns00a named[45171]: database: info: ADB memory usage
0x8011e8000: mem inuse 65536, overmem=0
407 MB RES at this point...
(max-cache-size still 32M)

--
Attila Nagy                                   e-mail: [hidden email]
Free Software Network (FSN.HU)                 phone: +3630 306 6758
http://www.fsn.hu/

_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

JINMEI Tatuya / 神明達哉-3
At Tue, 19 Feb 2008 14:59:15 +0100,
Attila Nagy <[hidden email]> wrote:

> > Okay, then please try this patch with '-n 1' (note: this patch doesn't
> > contain the memory statistics hack via the HTTP interface, but I don't
> > we don't need it for this test).

[...]

> (max-cache-size still 32M)

Hmm, then the mutex locks dynamically generated are also irrelevant.

I've also tried to reproduce the problem in a similar environment
(BIND 9.5.0b1 with threads on FreeBSD 7.0RC1/AMD64, cache-only
configuration, using a real query sample), unsuccessfully.  One
significant difference is that I disabled SMP in the kernel (it was
very unstable with the SMP support for some unknown reason), but I
doubt this is the key for the difference of the named behavior.

BTW, is this reproduceable on FreeBSD 6.x?  If so, then I'd like to
see what happens if you specify some small value of datasize
(e.g. 512MB) and have named abort when malloc() fails with the "X"
_malloc_options.  (This option doesn't seem to work for FreeBSD 7.x,
at least at the moment).

Some other questions:
- can we see your named.conf?  If you specify non-default
  configuration options, that might be the reason for, or related to,
  this problem.
- does your named produce lot of log messages?  If so, it might also
  be a reason (simply because it relies on standard libraries).

Thanks,

---
JINMEI, Tatuya
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

JINMEI Tatuya / 神明達哉-3
At Tue, 19 Feb 2008 20:30:07 -0700,
JINMEI Tatuya <[hidden email]> wrote:

> BTW, is this reproduceable on FreeBSD 6.x?  If so, then I'd like to
> see what happens if you specify some small value of datasize
> (e.g. 512MB) and have named abort when malloc() fails with the "X"
> _malloc_options.  (This option doesn't seem to work for FreeBSD 7.x,
> at least at the moment).

Okay, I've fond handier workaround (that should work for 7.X).  Please
try the following steps:

- create a symbolic link from "/etc/malloc.conf" to "X":
  # ln -s X /etc/malloc.conf
- start named with a moderate limitation of virtual memory size, e.g.
  # /usr/bin/limits -v 384m $path_to_named/named <command line options>

Then the named process will eventually abort itself with a core dump
due to malloc failure.  Please show us the stack trace at that point.
Hopefully it will reveal the malloc call that keeps consuming memory.

Notes:
- of course, this is a very radical way of diagnosing; you need to
  keep watching the process because it's "guaranteed" to be aborted.
- the VM size must be carefully chosen so that malloc failure won't
  happen due to normal named processing.  I think 384MB is reasonable
  enough according to the statistics you provided so far, but I'm not
  100% sure about that.
- it's better to keep my latest patch to adb.c and to run named with
  '-n 1' so that the mutex_init in adb.c won't trigger the malloc
  failure.
- the global symbolic link from /etc/make.conf affects other
  processes.  So, if you're running a different process than named
  that can consume a lot of memory or can cause malloc failure, we
  should find an alternative approach (there are some, but they are
  more complicated so let's discuss those only when they are really
  necessary).

Again, thanks for your cooperation.

---
JINMEI, Tatuya
Internet Systems Consortium, Inc.
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Bad bind performance with FreeBSD 7

Nagy, Attila
In reply to this post by Nagy, Attila
On 01/29/08 11:40, Attila Nagy wrote:
> ps: I have an other problem. I've recently switched from a last year
> 6-STABLE to 7-STABLE and got pretty bad results on the same machine
> with the same bind (9.4).
> The graphs are here:
> http://picasaweb.google.com/nagy.attila/20080129Fbsd6vs7Bind
The problem still persists and now I can provide some profiling info,
made by HWPMC.

The samples were collected from totally equal machines, the only
difference is the OS (FreeBSD 6-STABLE and FreeBSD 7-STABLE, amd64).

Here is FreeBSD/amd64 6-STABLE (compiled yesterday):
granularity: each sample hit covers 4 byte(s) for 0.00% of 158108.00 seconds

  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
  8.2   12909.00 12909.00        0  100.00%           SHA256_Transform [1]
  4.7   20408.00  7499.00        0  100.00%           kern_select [2]
  3.9   26594.00  6186.00        0  100.00%           swi_net [3]
  3.3   31829.00  5235.00        0  100.00%           sopoll [4]
  3.3   37059.00  5230.00        0  100.00%           syscall [5]
  3.3   42280.00  5221.00        0  100.00%           bcopy [6]
  3.2   47297.00  5017.00        0  100.00%           critical_exit [7]
  3.1   52274.00  4977.00        0  100.00%           Xfast_syscall [8]
  2.8   56748.00  4474.00        0  100.00%           spinlock_exit [9]
  2.8   61176.00  4428.00        0  100.00%           DELAY [10]
  2.5   65101.00  3925.00        0  100.00%           netisr_poll [11]
  2.1   68346.00  3245.00        0  100.00%           bge_rxeof [12]
  1.8   71126.00  2780.00        0  100.00%           copyout [13]
  1.7   73888.00  2762.00        0  100.00%           _mtx_lock_sleep [14]
  1.7   76641.00  2753.00        0  100.00%           soreceive [15]
  1.6   79245.00  2604.00        0  100.00%           rn_match [16]
  1.6   81769.00  2524.00        0  100.00%           selrecord [17]
  1.5   84187.00  2418.00        0  100.00%           netisr_pollmore [18]
  1.5   86526.00  2339.00        0  100.00%           copyin [19]
  1.5   88843.00  2317.00        0  100.00%           uma_zfree_arg [20]
  1.4   91011.00  2168.00        0  100.00%           uma_zalloc_arg [21]
  1.3   93118.00  2107.00        0  100.00%           soo_poll [22]
  1.1   94793.00  1675.00        0  100.00%           bge_poll [23]
  1.0   96428.00  1635.00        0  100.00%           spinlock_enter [24]

And here is FreeBSD/amd64 7-STABLE (also compiled yesterday):
granularity: each sample hit covers 4 byte(s) for 0.00% of 204813.00 seconds

  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
  9.5   19395.00 19395.00        0  100.00%           _mtx_lock_sleep [1]
  7.1   33844.00 14449.00        0  100.00%           SHA256_Transform [2]
  4.2   42408.00  8564.00        0  100.00%           DELAY [3]
  3.5   49583.00  7175.00        0  100.00%           kern_select [4]
  3.4   56565.00  6982.00        0  100.00%           syscall [5]
  3.2   63104.00  6539.00        0  100.00%           sopoll_generic [6]
  2.9   69125.00  6021.00        0  100.00%           Xfast_syscall [7]
  2.7   74615.00  5490.00        0  100.00%           bcopy [8]
  2.6   79947.00  5332.00        0  100.00%           swi_net [9]
  2.2   84515.00  4568.00        0  100.00%           critical_exit [10]
  1.9   88438.00  3923.00        0  100.00%           netisr_poll [11]
  1.8   92179.00  3741.00        0  100.00%           spinlock_exit [12]
  1.8   95882.00  3703.00        0  100.00%           copyout [13]
  1.7   99343.00  3461.00        0  100.00%           _thread_lock_flags
[14]
  1.6  102581.00  3238.00        0  100.00%           uma_zfree_arg [15]
  1.4  105358.00  2777.00        0  100.00%           spinlock_enter [16]
  1.2  107897.00  2539.00        0  100.00%           rn_match [17]
  1.2  110369.00  2472.00        0  100.00%           soreceive_generic [18]
  1.2  112814.00  2445.00        0  100.00%          
intr_event_schedule_thread [19]
  1.2  115194.00  2380.00        0  100.00%           uma_zalloc_arg [20]
  1.1  117417.00  2223.00        0  100.00%           netisr_pollmore [21]
  1.0  119444.00  2027.00        0  100.00%           selrecord [22]
  1.0  121450.00  2006.00        0  100.00%           copyin [23]
  1.0  123397.00  1947.00        0  100.00%           cpu_switch [24]

Here are the full output:
http://people.fsn.hu/~bra/freebsd/bind94-performance-fbsd6vs7-20080403/

At first glimpse it seems that there is a lot more time spent in
_mtx_lock_sleep in FreeBSD 7 than in FreeBSD 6...

--
Attila Nagy                                   e-mail: [hidden email]
Free Software Network (FSN.HU)                 phone: +3630 306 6758
http://www.fsn.hu/

_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: Bad bind performance with FreeBSD 7

Stefan Lambrev-2
Greetings,

Attila Nagy wrote:

> On 01/29/08 11:40, Attila Nagy wrote:
>> ps: I have an other problem. I've recently switched from a last year
>> 6-STABLE to 7-STABLE and got pretty bad results on the same machine
>> with the same bind (9.4).
>> The graphs are here:
>> http://picasaweb.google.com/nagy.attila/20080129Fbsd6vs7Bind
> The problem still persists and now I can provide some profiling info,
> made by HWPMC.
>
>
Sorry if you already answer this question, but at least I can find it in
the thread.
What scheduler are you using on RELENG_7 ?
Did you check with both schedulers (ule/4bsd) to see which one works
better for you?
Also are you sure that you service the same number of requests - I see
that the 6.x image shows CPU usage from
Aug 2007 and 7.x image is from Jan 2008 ...  is it possible, that you
have more requests and that's why your CPU usage increased?

--

Best Wishes,
Stefan Lambrev
ICQ# 24134177

_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: Bad bind performance with FreeBSD 7

Nagy, Attila
On 2008.04.03. 15:21, Stefan Lambrev wrote:

> Greetings,
>
> Attila Nagy wrote:
>> On 01/29/08 11:40, Attila Nagy wrote:
>>> ps: I have an other problem. I've recently switched from a last year
>>> 6-STABLE to 7-STABLE and got pretty bad results on the same machine
>>> with the same bind (9.4).
>>> The graphs are here:
>>> http://picasaweb.google.com/nagy.attila/20080129Fbsd6vs7Bind
>> The problem still persists and now I can provide some profiling info,
>> made by HWPMC.
>>
>>
> Sorry if you already answer this question, but at least I can find it
> in the thread.
> What scheduler are you using on RELENG_7 ?
> Did you check with both schedulers (ule/4bsd) to see which one works
> better for you?
> Also are you sure that you service the same number of requests - I see
> that the 6.x image shows CPU usage from
> Aug 2007 and 7.x image is from Jan 2008 ...  is it possible, that you
> have more requests and that's why your CPU usage increased?
As for the pictures: GENERIC kernels, so 4BSD on both versions (6 and 7).
As for the profiling info: 4BSD on 6, ULE on 7 (because both were
upgraded yesterday, and ULE is now default in RELENG_7)

The pictures are from the same timeframe (what aug 2007 refers to is the
time when the OS was compiled), the two machines were behind a per
packet load balancer, so yes: at least in pps, they've got exactly the
same traffic (of course it was possible be that one machine could serve
the answer directly from the cache, while the other had to go out, but
I've started them at the same time, so I think this effect was minimized).

_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

Nagy, Attila
In reply to this post by JINMEI Tatuya / 神明達哉-3
Sorry again for the long delay, I've got other work to do, and our 9.4
servers work fine (at least on FreeBSD 6, though, see the other
-performance- problem)...

On 02/20/08 04:30, JINMEI Tatuya / 神明達哉 wrote:

> At Tue, 19 Feb 2008 14:59:15 +0100,
> Attila Nagy <[hidden email]> wrote:
>
>  
>>> Okay, then please try this patch with '-n 1' (note: this patch doesn't
>>> contain the memory statistics hack via the HTTP interface, but I don't
>>> we don't need it for this test).
>>>      
>
> [...]
>
>  
>> (max-cache-size still 32M)
>>    
>
> Hmm, then the mutex locks dynamically generated are also irrelevant.
>
> I've also tried to reproduce the problem in a similar environment
> (BIND 9.5.0b1 with threads on FreeBSD 7.0RC1/AMD64, cache-only
> configuration, using a real query sample), unsuccessfully.  One
> significant difference is that I disabled SMP in the kernel (it was
> very unstable with the SMP support for some unknown reason), but I
> doubt this is the key for the difference of the named behavior.
>  
I don't know why am I the only one to see this.

> BTW, is this reproduceable on FreeBSD 6.x?  If so, then I'd like to
> see what happens if you specify some small value of datasize
> (e.g. 512MB) and have named abort when malloc() fails with the "X"
> _malloc_options.  (This option doesn't seem to work for FreeBSD 7.x,
> at least at the moment).
>  
Yes, it's the same, even when there is a different (libpthreads, KSE)
threading library is in use.
I've recompiled named with the following in main():
./work/bind-9.5.0b2/bin/named/main.c:   _malloc_options="X";

And set cache-size to 32MB.

At:
21664 bind        4  20    0   819M   819M kserel 0   5:32  0.00% named.950
I pressed a CTRL-C:
mem.c:1114: REQUIRE((((ctx) != ((void *)0)) && (((const isc__magic_t
*)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))))
failed.

> Some other questions:
> - can we see your named.conf?  If you specify non-default
>   configuration options, that might be the reason for, or related to,
>   this problem.
>  
Of course (see at the end).

> - does your named produce lot of log messages?  If so, it might also
>   be a reason (simply because it relies on standard libraries).
>  
grep named ns20080403.log | wc -l
1930006
For today (17 hours and 18 minutes of logs).
Is this a lot?

Config (normally max-cache-size is about 2400M):
-hmm I haven't tried to change cleaning-interval, it was needed because
the default cache housekeeping effectively stopped the ns during the
cleanup-

options {
        directory "/etc/bind";
        tcp-clients 256;
        recursive-clients 8192;
        max-cache-size 32M;
        minimal-responses yes;
        pid-file "/var/run/named.pid";
        cleaning-interval 15;
        allow-query-cache { any; };
        allow-query { any; };
        allow-recursion { any; };
};

controls {
        inet * port 953
                allow { } keys { "rndc-key"; };
};

key "rndc-key" {
        algorithm hmac-md5;
        secret
};

logging {
    channel syslog-ng {
        syslog local5;
        severity info;
        print-category yes;
        print-severity yes;
        };
    category default            { syslog-ng; };
    category config             { syslog-ng; };
    category xfer-in            { syslog-ng; };
    category xfer-out           { syslog-ng; };
    category notify             { syslog-ng; };
    category security           { syslog-ng; };
    category update             { syslog-ng; };
    category lame-servers       { syslog-ng; };
    category update-security    { syslog-ng; };
};

zone "10.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "16.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "17.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "18.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "19.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "20.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "21.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "22.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "23.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "24.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "25.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "26.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "27.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "28.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "29.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "30.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "31.172.in-addr.arpa" in { type master; file "db/db.rfc1918"; };
zone "168.192.in-addr.arpa" in { type master; file "db/db.rfc1918"; };


--
Attila Nagy                                   e-mail: [hidden email]
Free Software Network (FSN.HU)                 phone: +3630 306 6758
http://www.fsn.hu/

_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
Reply | Threaded
Open this post in threaded view
|

Re: max-cache-size doesn't work with 9.5.0b1

JINMEI Tatuya / 神明達哉-3
At Thu, 03 Apr 2008 17:22:38 +0200,
Attila Nagy <[hidden email]> wrote:

> Sorry again for the long delay, I've got other work to do, and our 9.4
> servers work fine (at least on FreeBSD 6, though, see the other
> -performance- problem)...

No problem, I understand testing a beta version cannot be a high
priority work.

> > BTW, is this reproduceable on FreeBSD 6.x?  If so, then I'd like to
> > see what happens if you specify some small value of datasize
> > (e.g. 512MB) and have named abort when malloc() fails with the "X"
> > _malloc_options.  (This option doesn't seem to work for FreeBSD 7.x,
> > at least at the moment).
> >  
> Yes, it's the same, even when there is a different (libpthreads, KSE)
> threading library is in use.
> I've recompiled named with the following in main():
> ./work/bind-9.5.0b2/bin/named/main.c:   _malloc_options="X";
>
> And set cache-size to 32MB.
>
> At:
> 21664 bind        4  20    0   819M   819M kserel 0   5:32  0.00% named.950
> I pressed a CTRL-C:
> mem.c:1114: REQUIRE((((ctx) != ((void *)0)) && (((const isc__magic_t
> *)(ctx))->magic == ((('M') << 24 | ('e') << 16 | ('m') << 8 | ('C'))))))
> failed.

Hmm, this is odd in two points:
1. the "X" malloc option doesn't seem to work as expected.  I expected
   a call to malloc() should trigger an assertion failure (within the
   malloc library) at a much earlier stage.  Does it change if you try
   the alternative debugging approach I mentioned before?  That is:
  - create a symbolic link from "/etc/malloc.conf" to "X":
    # ln -s X /etc/malloc.conf
  - start named with a moderate limitation of virtual memory size, e.g.
    # /usr/bin/limits -v 384m $path_to_named/named <command line options>

2. Whether it's related to this max-cache-size issue, the assertion
   failure in mem.c wasn't an expected result; this is likely to be a
   bug anyway.  If the process dumped a core, can you show the
   stack backtrace of it?
   (gdb) thread apply all bt full

> > Some other questions:
> > - can we see your named.conf?  If you specify non-default
> >   configuration options, that might be the reason for, or related to,
> >   this problem.
> >  
> Of course (see at the end).
>
> > - does your named produce lot of log messages?  If so, it might also
> >   be a reason (simply because it relies on standard libraries).
> >  
> grep named ns20080403.log | wc -l
> 1930006
> For today (17 hours and 18 minutes of logs).
> Is this a lot?

This means about 31 log messages per second.  This may not be
extremely frequent, but if some memory is lost for every log message,
I guess it could be a reason for the growing memory at the hight rate
we've seen.

What if you change the channel setting from:

>     channel syslog-ng {
>         syslog local5;
>         severity info;
>         print-category yes;
>         print-severity yes;
>         };

to this one?

     channel syslog-ng {
         null;
         severity info;
         print-category yes;
         print-severity yes;
         };

BTW,

> -hmm I haven't tried to change cleaning-interval, it was needed because
> the default cache housekeeping effectively stopped the ns during the
> cleanup-

This doesn't matter for 9.5.  It doesn't perform periodic cleaning
regardless of the value of cleaning-interval.

---
JINMEI, Tatuya
Internet Systems Consortium, Inc.
_______________________________________________
[hidden email] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "[hidden email]"
12