HSH_Lookup entered multiply - why could that happen?

[Nils Goroll]

Hi,

I am trying to understand under which circumstances in Varnish 2.0.3 HSH_Lookup 
could get entered entered multiply in succession in a restart-scenatio. The 
effect I am seeing is duplication of session objects on the waitinglist.

I was also considering duplication of output lines, but if I add a high 
resolution time stamp in HSH_Lookup's handling of busy objects,

	if (busy_o != NULL) {
		/* There are one or more busy objects, wait for them */
		if (sp->esis == 0)
			VTAILQ_INSERT_TAIL(&oh->waitinglist, sp, list);
		if (params->diag_bitmap & 0x20)
			WSP(sp, SLT_Debug,
			"%lld %p on waiting list %p <%s>", gethrtime(), sp, oh, oh->hash);
		sp->objhead = oh;
		Lck_Unlock(&oh->mtx);
		return (NULL);
	}


what I get is this (URL removed to protect the innocent):

    48 VCL_call     c recv lookup
    48 VCL_call     c hash hash
    48 Debug        c 24115201202978841 8d6278 on waiting list 8b72e0 <##URL##>
    48 VCL_call     c hash hash
    48 Debug        c 24115203101868689 8d6278 on waiting list 8b72e0 <##URL##>
    48 VCL_call     c hash hash
    48 Debug        c 24115203106349919 8d6278 on waiting list 8b72e0 <##URL##>
    48 VCL_call     c hash hash
    48 Debug        c 24115205121308416 8d6278 on waiting list 8b72e0 <##URL##>
    48 VCL_call     c hash hash
    48 Debug        c 24115205122330112 8d6278 on waiting list 8b72e0 <##URL##>
    48 VCL_call     c hash hash
    48 Debug        c 24115207141435616 8d6278 on waiting list 8b72e0 <##URL##>
    48 VCL_call     c hash hash
    48 Hit          c 1506286692

the restart VCL code basically is this:

sub vcl_recv {
     if (req.restarts == 0) {
	# set default backend and default grace
     } else if (req.restarts == 1) {
	set req.grace = 24h;
	# set other backend
     } else {
	error 503 "Retry count exceeded";
     }
}

Basically, what I am trying to achieve is to have restarts fall back to the cache.

I'd appreciate any pointers, at this point I really don't understand why the 
hash vcl should get invoked multiple times.

Thank you, Nils