Page MenuHomePhabricator

Port varnishlog.py to new VSL API
Closed, ResolvedPublic

Description

We need to port 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

ScriptPurpose
modules/varnish/files/varnishreqstatsProvides request counts / rates by HTTP method and status code.
modules/varnish/files/varnishstatsdReports backend response timing by backend.

Phase 1: Scripts needed for text role

ScriptPurpose
modules/varnish/files/varnishrlsTracks stats on ResourceLoader (load.php) requests.
modules/varnish/files/varnishxcpsReports protocol and cipher support stats based on X-Connection-Properties header.

Phase 2: Scripts needed for upload role

ScriptPurpose
modules/varnish/files/varnishmediaTracks stats on image requests.
modules/varnish/files/varnishprocessorLibrary, currently only used by varnishmedia.

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
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

ema triaged this task as Normal priority.Mar 4 2016, 3:13 PM
ema added a comment.EditedMar 4 2016, 4:34 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:

v3v4descremote party
RxHeaderReqHeader / RespHeader (from clients) BereqHeader / BerespHeader (from backends)Header receivedclient / backend
RxRequestReqMethodRequest method received from clientsclient
RxStatusBerespStatusStatus code received from backendbackend
RxURLReqURLURL received from a clientclient
TxURLBereqURLURL sent to a backendbackend
TxHeaderReqHeader / RespHeader (to clients) BereqHeader / BerespHeader (to backends)Header sentclient / backend
TxRequestBereqMethodRequest method sent to backendsbackend
TxStatusRespStatusStatus code sent to clientclient

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

ema moved this task from Triage to In Progress on the Traffic board.Mar 4 2016, 10:44 PM
elukey added a comment.Mar 7 2016, 9:52 AM

@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
ema added a comment.Mar 10 2016, 12:03 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

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