r2614 - trunk/varnish-cache/bin/varnishd

[Anders Nordby]

Hi,

This evening I got a high peaks for load and context switches in my
graphs again, while running with 2629 (and changeset 2614 removed). :-(

So I'm not sure how much impact 2614 has, but I'd still like for it to
be checked. Checking mutex contests while these peaks are going on I
didn't see much, but there sure is a lot of mutex operations going on
(catched this in just a few seconds):

 27837.73 Debug     MTX_LOCK(hcl_lookup,hash_classic.c,150,&hp->mtx)    
 27651.87 Debug     MTX_UNLOCK(SES_Charge,cache_session.c,253,&stat_mtx)
 27649.91 Debug
MTX_UNLOCK(SES_Charge,cache_session.c,238,&sp->srcaddr->sah-
 27643.01 Debug
MTX_LOCK(SES_Charge,cache_session.c,235,&sp->srcaddr->sah->m
 27561.59 Debug     MTX_UNLOCK(HSH_Deref,cache_hash.c,360,&oh->mtx)         
 27558.65 Debug     MTX_LOCK(HSH_Deref,cache_hash.c,351,&oh->mtx)         
 27555.72 Debug     MTX_LOCK(HSH_Lookup,cache_hash.c,196,&oh->mtx)  
 27499.97 Debug
MTX_UNLOCK(WRK_QueueSession,cache_pool.c,294,&qp->mtx)
 27499.97 Debug     MTX_UNLOCK(wrk_thread,cache_pool.c,243,&qp->mtx)
 27423.36 Debug     MTX_LOCK(WRK_QueueSession,cache_pool.c,288,&qp->mtx)
 27325.80 Debug     MTX_LOCK(wrk_thread,cache_pool.c,240,&qp->mtx)    
 27276.70 Debug     MTX_UNLOCK(HSH_Lookup,cache_hash.c,240,&oh->mtx)  
 27276.70 Debug     MTX_UNLOCK(hcl_deref,hash_classic.c,238,&hp->mtx)
 27276.70 Debug     MTX_UNLOCK(hcl_lookup,hash_classic.c,168,&hp->mtx)  
 27274.73 Debug     MTX_LOCK(hcl_deref,hash_classic.c,233,&hp->mtx)
 27144.03 Debug     MTX_LOCK(SES_Charge,cache_session.c,245,&stat_mtx)
  4813.93 Debug     MTX_UNLOCK(EXP_Touch,cache_expire.c,215,&exp_mtx)     
  4813.93 Debug     MTX_TRYLOCK(EXP_Touch,cache_expire.c,206,&exp_mtx) =
0 
  4588.45 Debug
MTX_LOCK(SES_Delete,cache_session.c,353,&ses_mem_mtx) 
  4588.45 Debug
MTX_UNLOCK(SES_Delete,cache_session.c,355,&ses_mem_mtx)
  4587.48 Debug
MTX_LOCK(ses_relsrcaddr,cache_session.c,201,&ch->mtx) 
  4587.48 Debug
MTX_UNLOCK(ses_relsrcaddr,cache_session.c,207,&ch->mtx)
  4304.97 Debug
MTX_LOCK(SES_RefSrcAddr,cache_session.c,143,&ch->mtx)  
  3531.52 Debug
MTX_UNLOCK(SES_RefSrcAddr,cache_session.c,158,&ch->mtx)

Anything to do about this?

A 1-second ktrace from the same time can be downloaded from:
http://anders.fupp.net/varnish/varnishd-ktrace-2008-04-13_22-05-27.out.gz

I am running FreeBSD 7.0-RELEASE/amd64. The number of hits per second is
only around 1200, but I have 3 million objects in the cache now.

Bye,
Anders.

On Sun, Apr 13, 2008 at 01:04:03AM +0200, Anders Nordby wrote:
> I mentioned to des previously that by going from trunk 2605 to 2614, my
> load and level of context switches per second grew a lot (during peaks),
> and sent a couple of graphs showing that.
> 
> I've now tracked the problem down to this particular patch. I can run
> with the latest trunk (2629), and by removing this changeset, my load
> and context switches graphs are like before.
> 
> Could you and/or Arjan please take look at this change again please.
> Running with or without -s malloc (which I've also been playing with
> lately) does not seem to make a difference, only applying/removing this
> changeset does.
> 
> PS2: I recently heard des' talk on "Light My Fire". Is there any chance
> it could catch things like this, changes that give a distinct and
> negative impact on performance?
> 
> Bye,
> Anders.
> 
> On Mon, Mar 31, 2008 at 01:49:21PM +0200, phk at projects.linpro.no wrote:
> > Author: phk
> > Date: 2008-03-31 13:49:20 +0200 (Mon, 31 Mar 2008)
> > New Revision: 2614
> > 
> > Modified:
> >    trunk/varnish-cache/bin/varnishd/cache_hash.c
> > Log:
> > Fix a memoryleak relating to hash strings, found by: Arjan (noosius).
> > 
> > 
> > 
> > Modified: trunk/varnish-cache/bin/varnishd/cache_hash.c
> > ===================================================================
> > --- trunk/varnish-cache/bin/varnishd/cache_hash.c	2008-03-31 11:47:15 UTC (rev 2613)
> > +++ trunk/varnish-cache/bin/varnishd/cache_hash.c	2008-03-31 11:49:20 UTC (rev 2614)
> > @@ -383,6 +383,7 @@
> >  	assert(VTAILQ_EMPTY(&oh->objects));
> >  	MTX_DESTROY(&oh->mtx);
> >  	VSL_stats->n_objecthead--;
> > +	free(oh->hash);
> >  	FREE_OBJ(oh);
> >  }
> >  
> > 
> > _______________________________________________
> > varnish-commit mailing list
> > varnish-commit at projects.linpro.no
> > http://projects.linpro.no/mailman/listinfo/varnish-commit
> 
> 
> -- 
> Anders.
> _______________________________________________
> varnish-dev mailing list
> varnish-dev at projects.linpro.no
> http://projects.linpro.no/mailman/listinfo/varnish-dev


-- 
Anders.