Varnish - Makes Websites Fly !

1. I have split logs per virtualhost for AWStats
2. In /var/log/varnish/, I expect log files like :
   • virtualhostA.myDomain.tld.log for everything about the website virtualhostA.myDomain.tld
   • virtualhostB.myDomain.tld.log for everything about the website virtualhostB.myDomain.tld
   • varnishncsa.log for everything else
3. I see "similar" (?) entries when viewing virtualhostA.myDomain.tld.log and varnishncsa.log

logfileForVirtualhost='virtualhostA.myDomain.tld.log'; logfileForEverythingElse='varnishncsa.log'; cd '/var/log/varnish'; randomLineNumber=$(shuf -i 1-$(wc -l "$logfileForVirtualhost" | cut -d' ' -f1) -n 1); regEx=$(awk -v lineNumber="$randomLineNumber" 'BEGIN{OFS=".*"} NR==lineNumber {print $1,$4,$7,$9,$11}' "$logfileForVirtualhost" | tr -d '[]'); grep -E "$regEx" "$logfileForVirtualhost" "$logfileForEverythingElse" | column -s ' ' -t

To setup logs (sources : stackoverflow.com, Varnish documentation, Varnishncsa documentation) :

If logging is setup fine and stopped working :

-rw-r--r-- 1 varnishlog varnishlog 0 Sep 9 02:16 /var/log/varnish/varnishncsa.log	empty file

This article is NOT about changing the default port Varnish is listening on. It is about a change in Varnish behavior after upgrading Debian on a server where Varnish was already running fine and listening on port 80.
For more information about the initial setup of Varnish, and about changing its default port, please read my Varnish setup article.

Proto	Recv-Q	Send-Q	Local Address		Foreign Address		State	User	Inode		PID/Program name
tcp	0	0	0.0.0.0:6081		0.0.0.0:*		LISTEN	0	833790406	5785/varnishd
tcp	0	0	127.0.0.1:6082		0.0.0.0:*		LISTEN	0	833790425	5785/varnishd

DAEMON_OPTS="-a :80 \

The root cause is that Debian Jessie doesn't use init.d as the init system anymore, but systemd instead. And /etc/default/varnish is only read by the /etc/init.d/varnish script, not by the systemd init script (/lib/systemd/system/varnish.service).

1. backup /etc/systemd/system/varnish.service (should be a symlink, but just in case ...)
2. cp /lib/systemd/system/varnish.service /etc/systemd/system/
3. open /etc/systemd/system/varnish.service with your favorite text editor :

   [Unit]
   Description=Varnish Cache, a high-performance HTTP accelerator
   
   [Service]
   Type=forking
   LimitNOFILE=131072
   LimitMEMLOCK=82000
   ExecStartPre=/usr/sbin/varnishd -C -f /etc/varnish/default.vcl
   ExecStart=/usr/sbin/varnishd -a :6081 -T localhost:6082 -f /etc/varnish/default.vcl -S /etc/varnish/secret -s malloc,256m
   ExecReload=/usr/share/varnish/reload-vcl
   
   [Install]
   WantedBy=multi-user.target

4. change that 6081 into 80
5. save, exit and restart Varnish : service varnish restart

   The good ol' /etc/init.d/varnish restart has no effect here (varnishd still listening on 6081). SysVinit vs systemd styles, I guess...

6. check : service varnish status

   ● varnish.service - Varnish Cache, a high-performance HTTP accelerator
   	Loaded: loaded (/lib/systemd/system/varnish.service; linked)
   	Active: active (running) since Tue 2016-01-05 21:17:24 CET; 4s ago
   Process: 7835 ExecStart=/usr/sbin/varnishd -a :80 -T localhost:6082 -f /etc/varnish/default.vcl -S /etc/varnish/secret -s malloc,256m (code=exited, status=0/SUCCESS)
   Process: 7824 ExecStartPre=/usr/sbin/varnishd -C -f /etc/varnish/default.vcl (code=exited, status=0/SUCCESS)
   Main PID: 7846 (varnishd)
   	CGroup: /system.slice/varnish.service
   		├─7846 /usr/sbin/varnishd -a :80 -T localhost:6082 -f /etc/varnish/default.vcl -S /etc/varnish/secret -s malloc,256m
   		└─7848 /usr/sbin/varnishd -a :80 -T localhost:6082 -f /etc/varnish/default.vcl -S /etc/varnish/secret -s malloc,256m

   You can see there not only the port it's listening to, but also the configuration file read at startup.
7. Confirm : netstat -laputen :

   Proto	Recv-Q	Send-Q	Local Address		Foreign Address		State	User	Inode		PID/Program name
   tcp	0	0	0.0.0.0:80		0.0.0.0:*		LISTEN	0	834168483	7846/varnishd
   tcp	0	0	127.0.0.1:6082		0.0.0.0:*		LISTEN	0	834168504	7846/varnishd

1GB on disk fixed-size cache file :

DAEMON_OPTS="-a :6081 \
	     -T localhost:6082 \
	     -b localhost:8080 \
	     -u varnish \
	     -g varnish \
	     -S /etc/varnish/secret \
	     -s file,/var/lib/varnish/$INSTANCE/varnish_storage.bin,1G"

256MB memory-based cache :

DAEMON_OPTS="-a :80 \
	     -T localhost:6082 \
	     -f /etc/varnish/default.vcl \
	     -S /etc/varnish/secret \
	     -s malloc,256m"

Installation on Debian Wheezy (source) :

Installation ok, is it already listening ?

Configuration :

## Alternative 2, Configuration with VCL
#
# Listen on port 6081, administration on localhost:6082, and forward to
# one content server selected by the vcl file, based on the request.
# Use a 256MB memory based cache.
#
DAEMON_OPTS="-a :6081 \
	     -T localhost:6082 \
	     -f /etc/varnish/default.vcl \
	     -S /etc/varnish/secret \
	     -s malloc,256m"

# Default backend definition. Set this to point to your content server.
backend default {
	.host = "127.0.0.1";
	.port = "8080";
	}

Varnish administration :

vcl_deliver

Called before a response object (from the cache or the web server) is sent to the requesting client.

vcl_fetch

Called when the request has been sent to the backend and a response has been received from the backend. Normal tasks here are to alter the response headers, trigger ESI processing, try alternate backend servers in case the request failed.
The request object req is still available. And there's also the backend response object beresp, containing HTTP headers from the backend. (details)

vcl_recv

Called after a request is received from the client, but before it is processed. Its purpose is to decide whether or not to serve the request, how to do it, and, if applicable, which backend to use. It also allows to alter the request (alter cookies, add / remove request headers).
Only the request object req is available.(details)

vcl_synth

Called to deliver a synthetic object, i.e. an object that is generated in VCL, not fetched from the backend. Its body may be constructed using the synthetic() function.

VCL workflow seen as a finite state machine (source) :

hit

Content is served from cache.

miss

Content has been searched in cache, not found, then requested to the backend, stored in cache and served.

pass

The request and subsequent response will be passed to and from the backend server. It won't be cached. pass can be called in both vcl_recv and vcl_fetch.