child process restarts frequently

[Håvard Futsæter]

Thanks for the quick reply!

Dag-Erling Smørgrav wrote:
> Håvard Futsæter <havard.futseter at met.no> writes:
>> This object is then requested and delivered from cache several times.
>> Then we see the following in the log, at a time immediately after
>> 14:59:27:
>>
>> 0 ExpPick        138012248
>> 0 VCL_call       timeout
>> 0 VCL_return     discard

>> ...immediately following this( ca.14:59:33 ) we get:
>>
>> 0 ExpBan         138012248 was banned
>> 0 CLI            Rd vcl.load boot /tmp/vcl.XXfdES7y
>> 0 CLI            Wr 0 200 Loaded "/tmp/vcl.XXfdES7y" as "boot"
>> 0 CLI            Rd vcl.use boot
>> 0 CLI            Wr 0 200
>> 0 CLI            Rd start
>> 0 CLI            Wr 0 200
> 
> The child process crashed while or immediately after recycling the
> discarded object.

>> The weird thing is that it seems to happen at the exact same time
>> every day. At 07:59 and 14:59 the child processs is restarted in the
>> manner shown above. We have a lot of requests which expires at each
>> whole hour, but I have no idea if this is related in any way.
> 
> Does your backend deliver objects which always expire at either 08:00 or
> 15:00?

Well, yes. The backend actually delivers objects that expire every hour
sharp. So, a bunch of objects( about 2000 - 2500) will be discarded
simultaneously, 30 seconds before each whole hour.

We have also found an interesting thing in the logs:

Immediately after object 138012248 was banned and the child was 
restarted, we see that a request was made for object 138012248 ( or 
rather, a request for the same url that this object represents).

Might this perhaps be an indication that Varnish gets into trouble when 
it receives a request for a resource while the cached object for this 
resource is beeing recycled?


-- 
Mvh,
Håvard Futsæter
Telefon: +47 22 96 32 69
Mobil:   +47 99 69 61 84