HSH_Lookup entered multiply - why could that happen?
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 Debugc 24115201202978841 8d6278 on waiting list 8b72e0 ##URL## 48 VCL_call c hash hash 48 Debugc 24115203101868689 8d6278 on waiting list 8b72e0 ##URL## 48 VCL_call c hash hash 48 Debugc 24115203106349919 8d6278 on waiting list 8b72e0 ##URL## 48 VCL_call c hash hash 48 Debugc 24115205121308416 8d6278 on waiting list 8b72e0 ##URL## 48 VCL_call c hash hash 48 Debugc 24115205122330112 8d6278 on waiting list 8b72e0 ##URL## 48 VCL_call c hash hash 48 Debugc 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 ___ varnish-dev mailing list varnish-dev@projects.linpro.no http://projects.linpro.no/mailman/listinfo/varnish-dev
Re: HSH_Lookup entered multiply - why could that happen?
Maybe I should also mention that I am trying to test the restart behavior by simulating a a slow and unresponsive backend using this VCL code: sub vcl_fetch { /* TEST CODE to test restarting REMOVE ME */ if ((req.url ~ MAGIC TESTING URL SUBSTRING) (req.restarts = 3)) { C{ sleep(2); }C return (restart); } Is there a better way to do this? ___ varnish-dev mailing list varnish-dev@projects.linpro.no http://projects.linpro.no/mailman/listinfo/varnish-dev
Re: HSH_Lookup entered multiply - why could that happen?
In message 4b1ffa7d.3020...@schokola.de, Nils Goroll writes: Hi, what I get is this (URL removed to protect the innocent): 48 VCL_call c recv lookup 48 VCL_call c hash hash 48 Debugc 24115201202978841 8d6278 on waiting list 8b72e0 ##URL## What happens here is that another client/thread holds this object busy while it is being fetched from the backend. Once the object is marked unbusy, the waiting threads are relased, and calls hash again. I'm not quite sure you you keep hitting it so many times, it smells like som weird situation where the object takes a long time to fetch, has no cacheability, but does not get marked pass in vcl_fetch ? Poul-Henning -- Poul-Henning Kamp | UNIX since Zilog Zeus 3.20 p...@freebsd.org | TCP/IP since RFC 956 FreeBSD committer | BSD since 4.3-tahoe Never attribute to malice what can adequately be explained by incompetence. ___ varnish-dev mailing list varnish-dev@projects.linpro.no http://projects.linpro.no/mailman/listinfo/varnish-dev
Solved: HSH_Lookup entered multiply - why could that happen?
Sorry, there's an easy answer to this: I was using varnishlog -o. Sorry, folks and thanks to all who have started thinking about this. Nils ___ varnish-dev mailing list varnish-dev@projects.linpro.no http://projects.linpro.no/mailman/listinfo/varnish-dev