Varnishd stops sending logs to VSM after a while

[Dridi Boukelmoune]

On Mon, Mar 17, 2014 at 8:46 AM, Dridi Boukelmoune
<dridi.boukelmoune at zenika.com> wrote:
> Hi,
>
> On Mon, Mar 17, 2014 at 7:51 AM, Cédric Jeanneret <varnish at tengu.ch> wrote:
>> Hello,
>>
>> Sorry for the delay, but…
>>
>> So, some more information:
>>
>> Logrotate:
>> this shouldn't be a problem, as logrotate doesn't touch the _.vsm file…
>>
>> Varnishncsa/Varnishlog:
>> I don't think the problem is on their side either, as they perform
>> read-only access to the _.vsm (tell me if I'm wrong with this statement)
>>
>> VSM:
>> the four varnishes had the very same problem this weekend (of course,
>> when nobody's here…). I'm keeping one of them at hand with the problem
>> "enabled" in order to be able to debug a bit.
>>
>> Here are what I can tell:
>>
>> Inodes:
>> indeed, the inodes aren't the same for the one used by the process
>> (marked as DEL in lsof, inode 264058) and the one on the system (268725).
>> Creation date of the system one: March 16, 2014, 16:10.
>>
>> After a quick look in the logs, it seems there's a configuration
>> modification at this very time: some filters were added, calling a
>> reload of the VCL.
>>
>> Please see bellow for the "hot-reload" script content.
>>
>> Is there anything weird in this script?
>>
>> Thank you in advance.
>>
>> Cheers,
>>
>> C.
>>
>>
>>
>> #!/bin/bash
>> # Reload a varnish config
>> # Author: Kristian Lyngstol
>>
>> # Original version:
>> http://kly.no/posts/2009_02_18__Easy_reloading_of_varnish__VCL__.html
>>
>> if [ $# -lt 1 -o $# -gt 2 ]; then
>>   echo "Usage: $0 vcl_file [secret_file]"
>>   exit 1
>> fi
>> FILE=$1
>>
>> if [ $# -eq 2 ]; then
>>   SECRET_OPT="-S $2"
>> fi
>>
>> # Hostname and management port
>> # (defined in /etc/default/varnish or on startup)
>> HOSTPORT="localhost:6082"
>> NOW=`date +%F_%T`
>>
>> error()
>> {
>>     echo 1>&2 "Failed to reload $FILE."
>>     exit 1
>> }
>> echo "@@@ Checking VCL file syntax:"
>> varnishd -d -s malloc -f $FILE < /dev/null || error
>
> Maybe this varnishd instance you bring up deletes the file and creates its own.
>
> Btw, why would you need a storage for a simple syntax check ?

Don't mind this question (and the other below). Your echo mislead me,
and you're checking the vcl syntax with the wrong arguments. See
varnishd(1) for the -C usage.

> And isn't your redirection from /dev/null in the wrong direction ?
>
> Dridi
>
>> echo -e "\n@@@ Loading new VCL file:"
>> varnishadm $SECRET_OPT -T $HOSTPORT vcl.load reload$NOW $FILE || error
>> varnishadm $SECRET_OPT -T $HOSTPORT vcl.use reload$NOW || error
>>
>>
>> echo -e "\n@@@ Currently available VCL configs:"
>> varnishadm $SECRET_OPT -T $HOSTPORT vcl.list
>>
>> exit 0
>>
>>
>> On 03/14/2014 10:01 PM, Stephen Wood wrote:
>>> My first thought is that logrotate is running and varishncsa is not
>>> properly catching a SIGHUP after a rotate. Therefore the logfile gets
>>> rotated but varnishncsa continues writing to the old fd.
>>>
>>> If you run varnishncsa by itself on the command line during these periods,
>>> do you get output? If so then it's probably not a problem with shared
>>> memory.
>>>
>>> If you want to test this, you can simply change the varnishncsa logrotate
>>> behavior to use copytruncate and not bother sending a HUP, which will
>>> truncate the log without rotating it.
>>>
>>> For reference here's what my logrotate file looks like:
>>>
>>> /var/log/varnish/varnish.log /var/log/varnish/varnishncsa.log {
>>>   size 1G
>>>   rotate 7
>>>   missingok
>>>   compress
>>>   delaycompress
>>>   postrotate
>>>     for service in varnishlog varnishncsa; do
>>>       if /usr/bin/pgrep -P 1 $service >/dev/null; then
>>>         service $service reload > /dev/null
>>>       fi
>>>     done
>>>   endscript
>>> }
>>>
>>> If you want to try copytruncate:
>>>
>>> /var/log/varnish/varnish.log /var/log/varnish/varnishncsa.log {
>>>   size 1G
>>>   rotate 7
>>>   missingok
>>>   compress
>>>   delaycompress
>>>   copytruncate
>>> }
>>>
>>> Note that you'll get a message in your log file that states it was
>>> truncated. It may mess up your log parsing software.
>>>
>>>
>>> On Thu, Mar 13, 2014 at 4:33 AM, Raymond Jennings <
>>> raymond.jennings at nytimes.com> wrote:
>>>
>>>> I have what might be a related problem.  I can only get varnishlog to
>>>> write to a file after I stop it and restart it.  I am running on ec2.
>>>> I tried various tricks to wait so many seconds after varnished starts
>>>> then start varnishlog.   Varnishncsa runs perfectly fine right out of
>>>> the gate.  I have had this problem for about two years now.
>>>> Varnishlog is clearly running and "service varnishlog stop"
>>>> successfully stops it.   "service varnishlog start" and things are
>>>> good.
>>>>
>>>>> On Mar 13, 2014, at 6:27 AM, Thomas Lecomte <
>>>> thomas.lecomte at virtual-expo.com> wrote:
>>>>>
>>>>>> On Thu, Mar 13, 2014 at 10:25:52AM +0100, Cédric Jeanneret wrote:
>>>>>>
>>>>>> Hmm, _.vsm is shown when we perform a simple "ls" in the directory...
>>>>>> Else, I would get some errors from either varnishncsa or varnishlog when
>>>>>> I start them (I tried that this morning, just to see what would
>>>> happen)...
>>>>>
>>>>> Maybe you could compare the inodes using ls -i on the visible _.vsm
>>>>> against the one shown by lsof on the varnish process.
>>>>>
>>>>> --
>>>>> Thomas Lecomte / +33 4 86 13 48 65
>>>>> Sysadmin / Virtual Expo / Marseille
>>>>>
>>>>> _______________________________________________
>>>>> varnish-misc mailing list
>>>>> varnish-misc at varnish-cache.org
>>>>> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>>>>
>>>> _______________________________________________
>>>> varnish-misc mailing list
>>>> varnish-misc at varnish-cache.org
>>>> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>>>>
>>>
>>>
>>>
>>>
>>>
>>> _______________________________________________
>>> varnish-misc mailing list
>>> varnish-misc at varnish-cache.org
>>> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
>>>
>>
>> _______________________________________________
>> varnish-misc mailing list
>> varnish-misc at varnish-cache.org
>> https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc