Port varnishlog.py to new VSL API
Closed, ResolvedPublic
Actions

Assigned To

Authored By

	• ema
	Mar 3 2016, 8:48 PM

Description

We need to port [[ https://github.com/wikimedia/operations-puppet/blob/production/modules/varnish/files/varnishlog.py | modules/varnish/files/varnishlog.py ]] (python bindings for the VSL API using ctypes) to the new VSL API.

python-varnishapi looks like a similar effort which supports Varnish 4.

The following programs depend on varnishlog.py:

modules/varnish/files/varnishmedia
modules/varnish/files/varnishprocessor/varnishprocessor.py
modules/varnish/files/varnishreqstats
modules/varnish/files/varnishrls
modules/varnish/files/varnishstatsd
modules/varnish/files/varnishxcps

Several of these scripts are only relevant to a particular cache role, so we can postpone migrating them until we're ready to migrate that particular role:

Phase 0: Scripts needed for all Varnish roles

Script	Purpose
modules/varnish/files/varnishreqstats	Provides request counts / rates by HTTP method and status code.
modules/varnish/files/varnishstatsd	Reports backend response timing by backend.

Phase 1: Scripts needed for text role

Script	Purpose
modules/varnish/files/varnishrls	Tracks stats on ResourceLoader (load.php) requests.
modules/varnish/files/varnishxcps	Reports protocol and cipher support stats based on X-Connection-Properties header.

Phase 2: Scripts needed for upload role

Script	Purpose
modules/varnish/files/varnishmedia	Tracks stats on image requests.
modules/varnish/files/varnishprocessor	Library, currently only used by varnishmedia.

Details

Subject	Repo	Branch	Lines +/-
Port varnishreqstats and varnishstatsd to new VSL API	operations/puppet	production	+455 -2
varnishlog4: reduce sleep time when no events are ready to 10ms	operations/puppet	production	+1 -1
Port varnishlog to new VSL API	operations/puppet	production	+927 -5

Customize query in gerrit

Related Objects
Search...

Status	Assigned	Task
		Restricted Task
Duplicate	None	T109331 Deleted files sometimes remain visible to non-privileged users if permanently linked
Duplicate	None	T133819 upload-lb.ulsfo.wikimedia.org still allow access to some deleted files
Open	None	T124286 [Epic] Wikidata language support
Open	None	T134592 Allow setting the UI to a language other than English for anonymous users
Duplicate	Nikerabbit	T149419 Interface language selection for unregistered users on Wikimedia projects
Invalid	None	T114662 RFC: Per-language URLs for multilingual wiki pages
Duplicate	BBlack	T119038 Image cache issue when 'over-writing' an image on commons
Resolved	• ema	T133821 Make CDN purges reliable
Resolved	• ema	T108580 HTTPS for internal service traffic
Invalid	None	T109325 Outbound HTTPS for varnish backend instances
Open	None	T122867 Evaluate the feasibility of cache invalidation for the action API
Resolved	• ema	T122881 Install XKey vmod
Declined	None	T142841 Sideways Only-If-Cached on misses at a primary DC
Resolved	• ema	T131499 Upgrade all cache clusters to Varnish 4
Resolved	• ema	T126206 Upgrade to Varnish 4: things to remember
Resolved	• ema	T122880 Evaluate and Test Limited Deployment of Varnish 4
Resolved	• ema	T128788 Port varnishlog.py to new VSL API

Event Timeline

• ema created this task.Mar 3 2016, 8:48 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptMar 3 2016, 8:48 PM

ori added a parent task: T126206: Upgrade to Varnish 4: things to remember.Mar 3 2016, 8:51 PM

ori added a parent task: T122880: Evaluate and Test Limited Deployment of Varnish 4.

• ema claimed this task.Mar 4 2016, 2:07 PM

Change 274946 had a related patch set uploaded (by Ema):
Port varnishlog to new VSL API

https://gerrit.wikimedia.org/r/274946

gerritbot added a project: Patch-For-Review.Mar 4 2016, 2:12 PM

• ema triaged this task as Medium priority.Mar 4 2016, 3:13 PM

Note that lots of tags have changed. Taking a quick look at varnishreqstats, for example, we need to fix: TxRequest, RxStatus, RxRequest, TxStatus, ReqEnd.

I couldn't find anything in the documentation mapping old tags to new ones, so here is a little lookup table:

v3	v4	desc	remote party
RxHeader	ReqHeader / RespHeader (from clients) BereqHeader / BerespHeader (from backends)	Header received	client / backend
RxRequest	ReqMethod	Request method received from clients	client
RxStatus	BerespStatus	Status code received from backend	backend
RxURL	ReqURL	URL received from a client	client
TxURL	BereqURL	URL sent to a backend	backend
TxHeader	ReqHeader / RespHeader (to clients) BereqHeader / BerespHeader (to backends)	Header sent	client / backend
TxRequest	BereqMethod	Request method sent to backends	backend
TxStatus	RespStatus	Status code sent to client	client

ReqEnd / BackendXID are gone and I couldn't find a v4 replacement.

• ema moved this task from Backlog to Traffic team actively servicing on the Traffic board.Mar 4 2016, 10:44 PM

@ema: I discovered an interesting thing from https://www.varnish-cache.org/docs/trunk/reference/vsl.html:

Timestamp - Timing information
Contains timing information for the Varnish worker threads.

Time stamps are issued by Varnish on certain events, and show the absolute time of the event, the time spent since the start of the work unit, and the time spent since the last timestamp was logged. See vsl(7) for information about the individual timestamps.

Theoretically the second field of Timestamp: Resp should give us ReqEnd:

Timestamp: Resp: 1457081583.011235 0.001619 0.000097

This is from a localhost request to a static HTML file, so it is saying ~1ms from start to request served to the client. Does it make any sense?

ori updated the task description. (Show Details)Mar 7 2016, 6:38 PM

varnishreqstats seems to be relatively easy to port: https://phabricator.wikimedia.org/P2736

The only part I'm not really sure about is the fact that ReqEnd is now gone. In the diff you can see I've used elif tag == 'Timestamp' and 'Resp' in value, which should essentially allow us to count when a client request has finished.

transaction_id: 32827, tag: Timestamp, value: Resp: 1457610147.609711 0.000065 0.000039, remote_party: client

Ottomata subscribed.Mar 10 2016, 2:19 PM

Change 274946 merged by Ema:
Port varnishlog to new VSL API

https://gerrit.wikimedia.org/r/274946

Change 277790 had a related patch set uploaded (by Ema):
Port varnishreqstats and varnishstatsd to new VSL API

https://gerrit.wikimedia.org/r/277790

Change 278894 had a related patch set uploaded (by Ema):
varnishlog4: reduce sleep time when no events are ready to 10ms

https://gerrit.wikimedia.org/r/278894

Change 278894 merged by Ema:
varnishlog4: reduce sleep time when no events are ready to 10ms

https://gerrit.wikimedia.org/r/278894

Change 277790 merged by Ema:
Port varnishreqstats and varnishstatsd to new VSL API

https://gerrit.wikimedia.org/r/277790

• ema closed this task as Resolved.Mar 31 2016, 1:51 PM

• MZMcBride subscribed.May 9 2016, 2:32 PM

Port varnishlog.py to new VSL APIClosed, ResolvedPublicActions