Varnishd stops sending logs to VSM after a while

Tue Mar 18 10:00:37 CET 2014

On Tue, Mar 18, 2014 at 9:48 AM, Cédric Jeanneret <varnish at tengu.ch> wrote:
> Hello Dridi
>
> On 03/17/2014 05:53 PM, Dridi Boukelmoune wrote:
>> On Mon, Mar 17, 2014 at 9:03 AM, Cédric Jeanneret <varnish at tengu.ch> wrote:
>>> Hello Dridi,
>>>
>>> that was it: the varnishd (run only in order to check the syntax,
>>> really, the reload itself is done later) was indeed overriding the _.vsm…
>>>
>>> I didn't thought about this first, because I wasn't aware it was taking
>>> using the already-present instance… Now, I updated the script in order
>>> to force the use of a new, temporary instance, forcing the user (-u) as
>>> well so that it will work in any cases.
>>
>> Check the varnishd(1) man page, there's a "-C" option you can use to
>> check the VCL syntax. And you can even skip this check, since
>> varnishadm will fail to vcl.load a bogus VCL.
>>
>> Cheers,
>> Dridi
>
> So it will fail with some error code if there's an error in the VCL?
> Will it also show the line error, like the current script does? I'll
> give it a try in order to see if this may replace the current varnishd call.
>
> Thanks for your support!

===
$ sudo varnishadm vcl.load test /etc/varnish/test.vcl
Message from VCC-compiler:
Expected an action, 'if', '{' or '}'
('input' Line 24 Pos 5)
    i f (req.request != "GET" &&
----#---------------------------

Running VCC-compiler failed, exit 1
VCL compilation failed
Command failed with error code 106
===

Enjoy ;)

Dridi

> Cheers,
>
> C.
>
>>
>>> This was a bit vicious :].
>>>
>>> Cheers,
>>>
>>> C.
>>>
>>> On 03/17/2014 08:46 AM, Dridi Boukelmoune 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 ?
>>>>
>>>> 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
>>>
>>> _______________________________________________
>>> 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