$30 off During Our Annual Pro Sale. View Details »

Varnish workshop - Drupal Europe 2018

Thijs Feryn
September 11, 2018

Varnish workshop - Drupal Europe 2018

See https://feryn.eu/speaking/varnish-workshop-drupal-europe-2018/ for more information about this Varnish workshop at Drupal Europe 2018.

Thijs Feryn

September 11, 2018
Tweet

More Decks by Thijs Feryn

Other Decks in Technology

Transcript

  1. Varnish workshop
    By Thijs Feryn

    View Slide

  2. Slow websites suck

    View Slide

  3. Web performance is
    an essential part of
    the user experience

    View Slide

  4. Slow ~ Down

    View Slide

  5. Saturated
    market

    View Slide

  6. View Slide

  7. View Slide

  8. View Slide

  9. View Slide

  10. Heavy load

    View Slide

  11. Mo money
    Mo servers

    View Slide

  12. Refactor slow code
    Write fast code

    View Slide

  13. After a while you
    hit the limits

    View Slide

  14. Cache

    View Slide

  15. Don’t
    recompute
    if the data
    hasn’t
    changed

    View Slide

  16. Caching is not a
    compensation for
    poor code

    View Slide

  17. Caching is an
    essential
    architectural
    strategy

    View Slide

  18. Hi, I’m Thijs

    View Slide

  19. I’m
    @ThijsFeryn
    on Twitter

    View Slide

  20. I’m an
    Evangelist
    At

    View Slide

  21. I’m an
    Evangelist
    At

    View Slide

  22. View Slide

  23. View Slide

  24. Normally
    User Server

    View Slide

  25. With Varnish
    User Varnish Server

    View Slide

  26. View Slide

  27. View Slide

  28. ✓ Page cache
    ✓ Dynamic page cache
    ✓ Render cache
    ✓ BigPipe
    ✓ BigPipe sessionless

    View Slide

  29. Install & configure

    View Slide

  30. https://packagecloud.io/varnishcache/varnish60
    https://packagecloud.io/varnishcache/varnish5
    https://packagecloud.io/varnishcache/varnish41

    View Slide

  31. $ curl -s https://packagecloud.io/install/repositories/
    varnishcache/varnish6/script.deb.sh | sudo bash
    $ apt-get install varnish
    Debian & Ubuntu

    View Slide

  32. $ apt-cache policy varnish
    varnish:
    Installed: 6.0.0-1~stretch
    Candidate: 6.0.0-1~stretch
    Version table:
    *** 6.0.0-1~stretch 500
    500 https://packagecloud.io/varnishcache/varnish60/debian stretch/main
    amd64 Packages
    100 /var/lib/dpkg/status amd64 Packages
    5.0.0-7+deb9u1 500
    500 http://deb.debian.org/debian stretch/main amd64 Packages
    500 http://security.debian.org stretch/updates/main amd64 Packages

    View Slide

  33. $ apt-get install varnish=6.0.0-1~stretch

    View Slide

  34. $ curl -s https://packagecloud.io/install/repositories/
    varnishcache/varnish60/script.rpm.sh | sudo bash
    $ yum install varnish
    RHEL & CentOS

    View Slide

  35. Config
    file

    View Slide

  36. -a: binding address & port
    -T: admin binding
    -f: VCL file
    -S: secret file
    -s: storage
    -j: jailing
    -l: shared memory log size
    -t: default TTL
    -p: runtime parameters
    Options

    View Slide

  37. DAEMON_OPTS="-j unix,user=www-data \
    -a main=0000:80 \
    -a proxy=0.0.0.0:81,PROXY \
    -T localhost:6082 \
    -f /etc/varnish/default.vcl \
    -S /etc/varnish/secret \
    -l 100m,10m \
    -t 60 \
    -p feature=+esi_disable_xml_check \
    -p feature=+http2 \
    -p connect_timeout=20s \
    -p first_byte_timeout=100s \
    -p between_bytes_timeout=5s \
    -s malloc,3g"

    View Slide

  38. The backend

    View Slide

  39. Other
    port
    Other IP
    Other
    server

    View Slide

  40. ✓In VCL file
    ✓In config file using "-b"
    Link backend to Varnish

    View Slide

  41. DAEMON_OPTS="-j unix,user=www-data \
    -a main=0.0.0.0:80 \
    -a proxy=0.0.0.0:81,PROXY \
    -T localhost:6082 \
    -b 127.0.0.1:8080 \
    -S /etc/varnish/secret \
    -s malloc,3g"
    Can't
    have -f
    In config file

    View Slide

  42. vcl 4.0;


    backend default {

    .host = "127.0.0.1";

    .port = "8080";

    }
    In VCL file
    Minimal
    VCL

    View Slide

  43. What about TLS/SSL?

    View Slide

  44. ✓HAProxy
    ✓Nginx
    ✓Pound
    ✓Hitch
    Terminate TLS/SSL

    View Slide

  45. HAProxy
    Varnish
    Nginx
    HTTP & HTTPS
    HTTP
    HTTP
    Certificates go here
    Public

    View Slide

  46. How do you know if it
    was HTTP or HTTPS?

    View Slide

  47. X-Forwarded-Proto: https
    X-Forwarded-Proto: http

    View Slide

  48. What’s the real IP?

    View Slide

  49. X-Forwarded-For

    View Slide

  50. Nginx
    Public
    172.18.0.1
    Client IP: 172.18.0.1
    X-Forwarded-For:

    View Slide

  51. Varnish
    172.18.0.8
    Nginx
    Public
    172.18.0.1
    Client IP: 172.18.0.8
    X-Forwarded-For: 172.18.0.1

    View Slide

  52. HAProxy
    172.18.0.3
    Varnish
    172.18.0.8
    Nginx
    Public
    172.18.0.1
    Client IP: 172.18.0.8
    X-Forwarded-For: 172.18.0.3

    View Slide

  53. PROXY Protocol

    View Slide

  54. Add original IP as
    TCP preamble

    View Slide

  55. DAEMON_OPTS="-j unix,user=www-data \
    -a :80 \
    -a :81,PROXY \
    -T localhost:6082 \
    -f /etc/varnish/default.vcl \
    -S /etc/varnish/secret \
    -l 100m,10m \
    -t 60 \
    -p feature=+esi_disable_xml_check \
    -p connect_timeout=20s \
    -p first_byte_timeout=100s \
    -p between_bytes_timeout=5s \
    -s malloc,3g"

    View Slide

  56. HAProxy
    172.18.0.3
    Varnish
    172.18.0.8
    Nginx
    Public
    172.18.0.1
    Client IP: 172.18.0.8
    X-Forwarded-For: 172.18.0.1

    View Slide

  57. View Slide

  58. $settings['reverse_proxy'] = TRUE;
    $settings['reverse_proxy_addresses'] = array('127.0.0.1');
    Drupal\Core\StackMiddleware\ReverseProxyMiddleware

    View Slide

  59. // Initialize proxy settings.
    if ($settings->get('reverse_proxy', FALSE)) {
    $ip_header = $settings->get('reverse_proxy_header', 'X_FORWARDED_FOR');
    $request::setTrustedHeaderName($request::HEADER_X_FORWARDED_FOR, $ip_header);
    $proto_header = $settings->get('reverse_proxy_proto_header', 'X_FORWARDED_PROTO');
    $request::setTrustedHeaderName($request::HEADER_X_FORWARDED_PROTO, $proto_header);
    $host_header = $settings->get('reverse_proxy_host_header', 'X_FORWARDED_HOST');
    $request::setTrustedHeaderName($request::HEADER_X_FORWARDED_HOST, $host_header);
    $port_header = $settings->get('reverse_proxy_port_header', 'X_FORWARDED_PORT');
    $request::setTrustedHeaderName($request::HEADER_X_FORWARDED_PORT, $port_header);
    $forwarded_header = $settings->get('reverse_proxy_forwarded_header', 'FORWARDED');
    $request::setTrustedHeaderName($request::HEADER_FORWARDED, $forwarded_header);
    $proxies = $settings->get('reverse_proxy_addresses', []);
    if (count($proxies) > 0) {
    $request::setTrustedProxies($proxies, Request::HEADER_X_FORWARDED_ALL |
    Request::HEADER_FORWARDED);
    }
    }
    Drupal\Core\StackMiddleware\ReverseProxyMiddleware

    View Slide

  60. There are rules

    View Slide

  61. ✓Idempotence
    ✓State
    ✓Expiration
    ✓Conditional requests
    ✓Cache variations
    Varnish speaks HTTP

    View Slide

  62. Idempotence
    Execute
    multiple
    times
    Result
    doesn't
    change

    View Slide

  63. ✓ GET
    ✓ HEAD
    - POST
    - PUT
    - DELETE
    - PATCH
    Idempotence
    Result
    changes
    Result
    doesn't
    change
    Don't
    cache

    View Slide

  64. State

    View Slide

  65. State
    ~
    user specific
    data
    Cookies
    Auth
    headers

    View Slide

  66. About cookies

    View Slide

  67. ✓ Request header
    ✓ Sent by client (~browser)
    ✓ Sent on every request
    ✓ Describes state
    ✓ Is not cached
    ✓ 3rd party tracking cookies vs own
    cookies
    About cookies
    Cookie: key=value;key2=value2

    View Slide

  68. ✓ Response header
    ✓ Sent by backend server
    ✓ Only when backend is called
    ✓ Changes state
    ✓ Is not cached
    ✓ Blacklisted for 120s (by default)
    About cookies
    Set-Cookie: key=another_value

    View Slide

  69. Time
    To
    Live

    View Slide

  70. 1.VCL
    2.s-maxage
    3.max-age
    4.expires
    5.Default value 120s
    TTL Order

    View Slide

  71. Cache-Control:
    public,
    max-age=1000,
    s-maxage=3600

    View Slide

  72. Use TTL not to cache
    Cache-Control: max-age=0
    Cache-Control: s-maxage=0
    Cache-Control: private
    Cache-Control: no-cache
    Cache-Control: no-store
    Expires: Fri, 1 Jan 1971 00:00:00 GMT

    View Slide

  73. Age
    Age: 10
    How old is the
    cached object?

    View Slide

  74. Real cache duration
    max-age - Age
    s-maxage - Age

    View Slide

  75. Don’t set the Age
    header yourself!

    View Slide

  76. Conditional
    requests

    View Slide

  77. Only fetch
    payload that has
    changed

    View Slide

  78. Otherwise:
    HTTP/1.1 304 Not Modified

    View Slide

  79. ✓ Conserve bandwidth
    ✓ Reduce load on the backend when
    revalidating
    Conditional requests

    View Slide

  80. Conditional requests
    HTTP/1.1 200 OK
    Host: localhost
    Etag: 7c9d70604c6061da9bb9377d3f00eb27
    Content-type: text/html; charset=UTF-8
    Hello world output
    GET / HTTP/1.1
    Host: localhost
    User-Agent: curl/7.48.0

    View Slide

  81. Conditional requests
    HTTP/1.0 304 Not Modified
    Host: localhost
    Etag: 7c9d70604c6061da9bb9377d3f00eb27
    GET / HTTP/1.1
    Host: localhost
    User-Agent: curl/7.48.0
    If-None-Match:
    7c9d70604c6061da9bb9377d3f00eb27

    View Slide

  82. Conditional requests
    HTTP/1.1 200 OK
    Host: localhost
    Last-Modified: Fri, 22 Jul 2016 10:11:16 GMT
    Content-type: text/html; charset=UTF-8
    Hello world output
    GET / HTTP/1.1
    Host: localhost
    User-Agent: curl/7.48.0

    View Slide

  83. Conditional requests
    HTTP/1.0 304 Not Modified
    Host: localhost
    Last-Modified: Fri, 22 Jul 2016 10:11:16 GMT
    GET / HTTP/1.1
    Host: localhost
    User-Agent: curl/7.48.0
    If-Last-Modified: Fri, 22 Jul 2016 10:11:16
    GMT

    View Slide

  84. Store etag or
    modification date

    View Slide

  85. Validate early on

    View Slide

  86. Exit quickly

    View Slide

  87. View Slide

  88. $last_modified = $response->getLastModified();
    if ($last_modified) {
    // See if the client has provided the required HTTP headers.
    $if_modified_since = $request->server->has('HTTP_IF_MODIFIED_SINCE') ? strtotime($request->server-
    >get('HTTP_IF_MODIFIED_SINCE')) : FALSE;
    $if_none_match = $request->server->has('HTTP_IF_NONE_MATCH') ? stripslashes($request->server-
    >get('HTTP_IF_NONE_MATCH')) : FALSE;
    if ($if_modified_since && $if_none_match
    // etag must match.
    && $if_none_match == $response->getEtag()
    // if-modified-since must match.
    && $if_modified_since == $last_modified->getTimestamp()) {
    $response->setStatusCode(304);
    $response->setContent(NULL);
    // In the case of a 304 response, certain headers must be sent, and the
    // remaining may not (see RFC 2616, section 10.3.5).
    foreach (array_keys($response->headers->all()) as $name) {
    if (!in_array($name, ['content-location', 'expires', 'cache-control', 'vary'])) {
    $response->headers->remove($name);
    }
    }
    }
    }
    Drupal\page_cache\StackMiddleware\PageCache

    View Slide

  89. Varnish can revalidate
    aynchronously

    View Slide

  90. In both directions
    User Varnish Server
    304 Not Modified 304 Not Modified

    View Slide

  91. And serve stale data while
    that happens

    View Slide

  92. Grace mode

    View Slide

  93. Effective TTL = TTL + grace

    View Slide

  94. Cache-Control: public, max-age=100, s-maxage=3600,
    stale-while-revalidate=7200
    Stale-While-Revalidate
    Set grace mode

    View Slide

  95. Variations

    View Slide

  96. Cache is
    not the
    same for
    everyone

    View Slide

  97. ✓ URL
    ✓ Hostname
    ✓ IP if hostname is not set
    ✓ Vary header
    Basic variations

    View Slide

  98. Vary header
    Vary: Accept-Encoding
    Vary: Accept-Language
    Vary: Cookie
    Watch out!

    View Slide

  99. The flow

    View Slide

  100. View Slide

  101. View Slide

  102. Varnish
    Configuration
    Language

    View Slide

  103. DSL compiled
    and linked as
    shared object

    View Slide

  104. /etc/varnish/default.vcl

    View Slide

  105. Hooks
    &
    subroutines

    View Slide

  106. ✓vcl_recv: receive request
    ✓vcl_hash: compose cache key
    ✓vcl_miss: not found in cache
    ✓vcl_hit: found in cache
    ✓vcl_pass: don’t store in cache
    ✓vcl_pipe: bypass cache
    ✓vcl_backend_fetch: connect to
    backend
    ✓vcl_backend_response: response from
    backend
    ✓vcl_backend_error: backend fetch
    failed

    View Slide

  107. ✓vcl_purge: after successful purge
    ✓vcl_synth: send synthetic output
    ✓vcl_deliver: return data to client
    ✓vcl_init: initialize VMODs
    ✓vcl_fini: discard VMODs
    ✓vcl_fail: stop execution

    View Slide

  108. Actions

    View Slide

  109. ✓ hash: lookup in cache
    ✓ pass: don't cache
    ✓ synth: synthetic HTML output
    ✓ pipe: bypass cache
    ✓ purge: remove from cache
    VCL_RECV

    View Slide

  110. ✓ synth: synthetic HTML output
    ✓ pipe: bypass cache
    VCL_PIPE

    View Slide

  111. ✓ fetch: fetch data from
    backend, don't cache
    ✓ restart: restart transaction
    ✓ synth: synthetic HTML output
    VCL_PASS

    View Slide

  112. ✓ deliver: send cached object
    ✓ miss: synchronous refresh
    despite hit
    ✓ pass: fetch data from
    backend despite hit, don't
    cache
    ✓ restart: restart transaction
    ✓ synth: synthetic HTML output
    VCL_HIT

    View Slide

  113. ✓ fetch: fetch data from
    backend
    ✓ pass: fetch data from
    backend, don't cache
    ✓ restart: restart transaction
    ✓ synth: synthetic HTML output
    VCL_MISS

    View Slide

  114. ✓ lookup: look for cached
    object by using hash key
    VCL_HASH

    View Slide

  115. ✓ restart: restart transaction
    ✓ synth: synthetic HTML output
    VCL_PURGE

    View Slide

  116. ✓ deliver: deliver object to
    client
    ✓ restart: restart transaction
    ✓ synth: synthetic HTML output
    VCL_DELIVER

    View Slide

  117. ✓ deliver: deliver synthetic
    output to client
    ✓ restart: restart transaction
    VCL_SYNTH

    View Slide

  118. ✓ fetch: fetch object from
    backend
    ✓ abandon: abandon request
    and send HTTP 503 error
    VCL_BACKEND_FETCH

    View Slide

  119. ✓ deliver: send fetched data to
    client
    ✓ abandon: abandon request
    and send HTTP 503 error
    ✓ retry: retry backend request
    VCL_BACKEND_RESPONSE

    View Slide

  120. ✓ deliver: send fetched data to
    client
    ✓ retry: retry backend request
    VCL_BACKEND_ERROR

    View Slide

  121. Typical flows

    View Slide

  122. ✓ vcl_recv: hash
    ✓ vcl_hash: lookup
    ✓ vcl_miss: fetch
    ✓ vcl_backend_request: fetch
    ✓ vcl_backend_response: deliver
    ✓ vcl_deliver: deliver
    MISS

    View Slide

  123. ✓ vcl_recv: hash
    ✓ vcl_hash: lookup
    ✓ vcl_hit: deliver
    ✓ vcl_deliver: deliver
    HIT

    View Slide

  124. ✓ vcl_recv: pass
    ✓ vcl_pass: fetch
    ✓ vcl_backend_request: fetch
    ✓ vcl_backend_response: deliver
    ✓ vcl_deliver: deliver
    PASS

    View Slide

  125. Objects

    View Slide

  126. ✓ req: incoming request object
    ✓ req_top: top level esi request
    ✓ bereq: request object to send to
    backend
    ✓ beresp: backend response
    ✓ resp: response to send back to
    client
    ✓ obj: cached object
    ✓ client: client information
    ✓ server: server information
    ✓ local: local TCP information
    ✓ remote: remote TCP information
    ✓ storage: storage information
    VCL Objects

    View Slide

  127. Variables

    View Slide

  128. ✓ req.url
    ✓ req.http.host
    ✓ req.http.user-agent
    ✓ req.backend_hint
    ✓ req.method
    ✓ …
    req variables

    View Slide

  129. ✓ bereq.backend
    ✓ bereq.http.user-agent
    ✓ bereq.method
    ✓ bereq.url
    ✓ …
    bereq variables

    View Slide

  130. ✓ beresp.age
    ✓ beresp.backend.ip
    ✓ beresp.backend.name
    ✓ beresp.do_esi
    ✓ beresp.grace
    ✓ beresp.keep
    ✓ beresp.http.set-cookie
    ✓ beresp.ttl
    ✓ beresp.status
    ✓ beresp.uncacheable
    beresp variables

    View Slide

  131. ✓ client.ip
    ✓ client.identity
    client variables
    local variables
    ✓ local.ip
    remote variables
    ✓ remote.ip

    View Slide

  132. ✓ obj.age
    ✓ obj.grace
    ✓ obj.hits
    ✓ obj.http.cache-control
    ✓ obj.reason
    ✓ obj.status
    ✓ obj.ttl
    object variables

    View Slide

  133. ✓ resp.http.user-agent
    ✓ resp.is_streaming
    ✓ resp.reason
    ✓ resp.status
    resp variables

    View Slide

  134. Default
    behaviour

    View Slide

  135. vcl 4.0;
    sub vcl_recv {
    if (req.method != "GET" &&
    req.method != "HEAD" &&
    req.method != "PUT" &&
    req.method != "POST" &&
    req.method != "TRACE" &&
    req.method != "OPTIONS" &&
    req.method != “PATCH" &&
    req.method != "DELETE") {
    return (pipe);
    }
    if (req.method != "GET" && req.method != "HEAD") {
    return (pass);
    }
    if (req.http.Authorization || req.http.Cookie) {
    return (pass);
    }
    return (hash);
    }
    Idempotence
    State
    Action
    Receive
    request

    View Slide

  136. sub vcl_hash {
    hash_data(req.url);
    if (req.http.host) {
    hash_data(req.http.host);
    } else {
    hash_data(server.ip);
    }
    return (lookup);
    }
    Lookup in
    cache
    Variations
    Action

    View Slide

  137. sub vcl_purge {
    return (synth(200, "Purged"));
    }
    sub vcl_hit {
    if (obj.ttl >= 0s) {
    return (deliver);
    }
    if (obj.ttl + obj.grace > 0s) {
    return (deliver);
    }
    return (miss);
    }
    sub vcl_miss {
    return (fetch);
    }
    sub vcl_deliver {
    return (deliver);
    }
    Remove
    from cache
    Found in
    cache
    Not found in
    cache
    Return
    HTTP response to
    client

    View Slide

  138. sub vcl_synth {
    set resp.http.Content-Type = "text/html; charset=utf-8";
    set resp.http.Retry-After = "5";
    synthetic( {"


    "} + resp.status + " " + resp.reason + {"


    Error "} + resp.status + " " + resp.reason + {"
    "} + resp.reason + {"
    Guru Meditation:
    XID: "} + req.xid + {"

    Varnish cache server


    "} );
    return (deliver);
    }
    Send
    custom HTML

    View Slide

  139. sub vcl_backend_fetch {
    return (fetch);
    }
    sub vcl_backend_response {
    if (bereq.uncacheable) {
    return (deliver);
    } else if (beresp.ttl <= 0s ||
    beresp.http.Set-Cookie ||
    beresp.http.Surrogate-control ~ "no-store" ||
    (!beresp.http.Surrogate-Control &&
    beresp.http.Cache-Control ~ "no-cache|no-store|private") ||
    beresp.http.Vary == "*") {
    set beresp.ttl = 120s;
    set beresp.uncacheable = true;
    }
    return (deliver);
    }
    Send
    backend
    request
    Receive
    backend
    response
    TTL
    State
    Receive
    backend
    response

    View Slide

  140. sub vcl_backend_error {
    set beresp.http.Content-Type = "text/html; charset=utf-8";
    set beresp.http.Retry-After = "5";
    synthetic( {"


    "} + beresp.status + " " + beresp.reason + {"


    Error "} + beresp.status + " " + beresp.reason + {"
    "} + beresp.reason + {"
    Guru Meditation:
    XID: "} + bereq.xid + {"

    Varnish cache server


    "} );
    return (deliver);
    }
    Send
    custom HTML on
    backend error

    View Slide

  141. In an ideal world

    View Slide

  142. HTTP best practices
    >
    custom VCL

    View Slide

  143. Reality
    sucks

    View Slide

  144. View Slide

  145. View Slide

  146. Don’t trust the end-user

    View Slide

  147. Cache-control ?

    View Slide

  148. Legacy

    View Slide

  149. Write VCL

    View Slide

  150. Normalize

    View Slide

  151. set req.http.Host = regsub(req.http.Host, ":[0-9]+", "");
    set req.url = std.querysort(req.url);
    if (req.url ~ "(\?|&)(utm_source|utm_medium|utm_campaign|utm_content|gclid|cx|ie|
    cof|siteurl)=") {
    set req.url = regsuball(req.url, "&(utm_source|utm_medium|utm_campaign|
    utm_content|gclid|cx|ie|cof|siteurl)=([A-z0-9_\-\.%25]+)", "");
    set req.url = regsuball(req.url, "\?(utm_source|utm_medium|utm_campaign|
    utm_content|gclid|cx|ie|cof|siteurl)=([A-z0-9_\-\.%25]+)", "?");
    set req.url = regsub(req.url, "\?&", "?");
    set req.url = regsub(req.url, "\?$", "");
    }
    if (req.url ~ "\#") {
    set req.url = regsub(req.url, "\#.*$", "");
    }
    if (req.url ~ "\?$") {
    set req.url = regsub(req.url, "\?$", "");
    }
    Normalize

    View Slide

  152. Static assets

    View Slide

  153. vcl 4.0;
    sub vcl_recv {
    if (req.url ~ "^[^?]*\.(7z|avi|bmp|bz2|css|csv|doc|docx|eot|flac|flv|gif|gz|ico|jpeg|
    jpg|js|less|mka|mkv|mov|mp3|mp4|mpeg|mpg|odt|otf|ogg|ogm|opus|pdf|png|ppt|pptx|rar|rtf|
    svg|svgz|swf|tar|tbz|tgz|ttf|txt|txz|wav|webm|webp|woff|woff2|xls|xlsx|xml|xz|zip)
    (\?.*)?$") {
    unset req.http.Cookie;
    return (hash);
    }
    }
    sub vcl_backend_response {
    if (bereq.url ~ "^[^?]*\.(7z|avi|bmp|bz2|css|csv|doc|docx|eot|flac|flv|gif|gz|ico|
    jpeg|jpg|js|less|mka|mkv|mov|mp3|mp4|mpeg|mpg|odt|otf|ogg|ogm|opus|pdf|png|ppt|pptx|
    rar|rtf|svg|svgz|swf|tar|tbz|tgz|ttf|txt|txz|wav|webm|webp|woff|woff2|xls|xlsx|xml|xz|
    zip)(\?.*)?$") {
    unset beresp.http.set-cookie;
    }
    if (bereq.url ~ "^[^?]*\.(7z|avi|bz2|flac|flv|gz|mka|mkv|mov|mp3|mp4|mpeg|mpg|ogg|ogm|
    opus|rar|tar|tgz|tbz|txz|wav|webm|xz|zip)(\?.*)?$") {
    unset beresp.http.set-cookie;
    set beresp.do_stream = true;
    set beresp.do_gzip = false;
    }
    }
    Cache static assets

    View Slide

  154. Do you really
    want to cache
    static assets?

    View Slide

  155. Nginx or
    Apache can
    be fast
    enough for
    that

    View Slide

  156. vcl 4.0;
    import std;
    sub vcl_recv {
    if (req.url ~ "^[^?]*\.(7z|avi|bmp|bz2|css|csv|doc|docx|eot|flac|flv|
    gif|gz|ico|jpeg|jpg|js|less|mka|mkv|mov|mp3|mp4|mpeg|mpg|odt|otf|ogg|
    ogm|opus|pdf|png|ppt|pptx|rar|rtf|svg|svgz|swf|tar|tbz|tgz|ttf|txt|txz|
    wav|webm|webp|woff|woff2|xls|xlsx|xml|xz|zip)(\?.*)?$") {
    unset req.http.Cookie;
    return (pass);
    }
    }
    Don’t cache static assets

    View Slide

  157. Blacklist/whitelist

    View Slide

  158. sub vcl_recv {
    if (req.url ~ "^/status\.php$" ||
    req.url ~ "^/update\.php$" ||
    req.url ~ "^/admin$" ||
    req.url ~ "^/admin/.*$" ||
    req.url ~ "^/flag/.*$" ||
    req.url ~ "^.*/ajax/.*$" ||
    req.url ~ "^.*/ahah/.*$") {
    return (pass);
    }
    }
    URL blacklist

    View Slide

  159. sub vcl_recv {
    if (req.url ~ "^/some-page/?"
    return (hash);
    }
    }
    URL whitelist

    View Slide

  160. if (beresp.http.Surrogate-Control ~ "BigPipe/1.0") {
    set beresp.do_stream = true;
    set beresp.ttl = 0s;
    }
    Don't cache BigPipe
    responses

    View Slide

  161. Those damn
    cookies again!

    View Slide

  162. vcl 4.0;
    sub vcl_recv {
    if (req.http.Cookie) {
    set req.http.Cookie = ";" + req.http.Cookie;
    set req.http.Cookie = regsuball(req.http.Cookie, "; +", ";");
    set req.http.Cookie = regsuball(req.http.Cookie,
    ";(SESS[a-z0-9]+|SSESS[a-z0-9]+|NO_CACHE)=", "; \1=");
    set req.http.Cookie = regsuball(req.http.Cookie, ";[^ ][^;]*", "");
    set req.http.Cookie = regsuball(req.http.Cookie, "^[; ]+|[; ]+$", "");
    if (req.http.Cookie == "") {
    unset req.http.Cookie;
    }
    else {
    return (pass);
    }
    }
    }
    Only keep Drupal cookies

    View Slide

  163. sub vcl_recv {
    if (req.http.Cookie) {
    set req.http.Cookie = ";" + req.http.Cookie;
    set req.http.Cookie = regsuball(req.http.Cookie, "; +", ";");
    set req.http.Cookie = regsuball(req.http.Cookie, ";(language)=", "; \1=");
    set req.http.Cookie = regsuball(req.http.Cookie, ";[^ ][^;]*", "");
    set req.http.Cookie = regsuball(req.http.Cookie, "^[; ]+|[; ]+$", "");
    if (req.http.cookie ~ "^\s*$") {
    unset req.http.cookie;
    return(pass);
    }
    return(hash);
    }
    }
    sub vcl_hash {
    hash_data(regsub( req.http.Cookie, "^.*language=([^;]*);*.*$", "\1" ));
    }
    Language cookie cache variation

    View Slide

  164. sub vcl_recv {
    return(hash);
    }
    Cache, even with cookies

    View Slide

  165. sub vcl_hash {
    hash_data(req.http.Cookie);
    }
    Hash all cookies

    View Slide

  166. Block caching

    View Slide

  167. View Slide

  168. Code
    renders
    single HTTP
    response

    View Slide

  169. Lowest
    denominator:
    no cache

    View Slide


  170. Edge Side Includes
    ✓Placeholder
    ✓Parsed by Varnish
    ✓Output is a composition of blocks
    ✓State per block
    ✓TTL per block

    View Slide

  171. sub vcl_recv {
    set req.http.Surrogate-Capability = "key=ESI/1.0";
    }
    sub vcl_backend_response {
    if (beresp.http.Surrogate-Control ~ "ESI/1.0") {
    unset beresp.http.Surrogate-Control;
    set beresp.do_esi = true;
    }
    }
    Edge Side Includes

    View Slide

  172. header("Cache-Control: public,must-revalidate,s-maxage=10");
    echo "Date in the ESI tag: ".date('Y-m-d H:i:s').'
    ';
    header("Cache-Control: no-store");
    header(“Surrogate-Control: content='ESI/1.0'");
    echo ''.PHP_EOL;
    echo "Date in the main page: ".date('Y-m-d H:i:s').'
    ';
    Main page
    ESI frame:
    esi.php
    Cached for
    10 seconds
    Not cached

    View Slide

  173. ESI_xmlerror No ESI processing, first char not '<'. (See
    feature esi_disable_xml_check)
    Expects HTML/
    XML tags

    View Slide

  174. -p feature=+esi_disable_xml_check
    Add as
    startup option

    View Slide

  175. req_top
    Get
    information about
    parent request in an
    ESI call

    View Slide

  176. vcl 4.0;
    backend default {
    .host = "nginx";
    .port = "80";
    }
    sub vcl_recv {
    if (req.esi_level > 0) {
    set req.http.x-parent-url = req_top.url;
    }
    }
    sub vcl_backend_response {
    if (beresp.http.Surrogate-Control ~ "ESI/1.0") {
    unset beresp.http.Surrogate-Control;
    set beresp.do_esi = true;
    }
    }
    Get parent URL

    View Slide

  177. ESI
    vs
    AJAX

    View Slide

  178. ✓ Server-side
    ✓ Standardized
    ✓ Processed on the
    “edge”, no in the
    browser
    ✓ Generally faster
    Edge-Side Includes
    - Sequential
    - One fails, all fail
    - Limited
    implementation in
    Varnish
    - Not that common

    View Slide

  179. ✓ Client-side
    ✓ Common knowledge
    ✓ Parallel processing
    ✓ Graceful
    degradation
    AJAX
    - Processed by the
    browser
    - Extra roundtrips
    - Somewhat slower

    View Slide

  180. Choose wisely

    View Slide

  181. View Slide

  182. Auto-placeholdering

    View Slide

  183. BigPipe

    View Slide

  184. id="callback=Drupal%5CCore%5CRender%5CElem
    ent%5CStatusMessages%3A%3ArenderMessages&a
    mp;args%5B0%5D&token=_HAdUpwWmet0TOTe2
    PSiJuMntExoshbm1kh2wQzzzAA">

    View Slide

  185. replacement-for-placeholder-with-
    id="callback=Drupal%5CCore%5CRender%5CElement%5CStatusMessages%3A%3A
    renderMessages&args%5B0%5D&token=_HAdUpwWmet0TOTe2PSiJuMntEx
    oshbm1kh2wQzzzAA">
    [{"command":"insert","method":"replaceWith","selector":"[data-big-
    pipe-placeholder-
    id=\u0022callback=Drupal%5CCore%5CRender%5CElement%5CStatusMessages%
    3A%3ArenderMessages\u0026args%5B0%5D\u0026token=_HAdUpwWmet0TOTe2PSi
    JuMntExoshbm1kh2wQzzzAA\u0022]","data":"","settings":null}]

    View Slide

  186. https://github.com/ThijsFeryn/drupal8_esi_placeholders

    View Slide

  187. services:
    esi:
    class: Symfony\Component\HttpKernel\HttpCache\Esi
    esi_placeholders.esi_subscriber:
    class: Drupal\esi_placeholders\EventSubscriber\EsiSubscriber
    arguments: ['@esi']
    tags:
    - { name: event_subscriber }
    esi_placeholders.placeholder_strategy.esi:
    class: Drupal\esi_placeholders\Render\Placeholder\EsiStrategy
    arguments: ['@request_stack','@esi']
    tags:
    - { name: placeholder_strategy, priority: 0 }

    View Slide

  188. esi_placeholders.esi_block_rendering:
    path: '/esi/block'
    defaults:
    _controller:
    '\Drupal\esi_placeholders\Controller\EsiController:returnEsiBlo
    ckContent'
    _title: 'ESI content'
    requirements:
    _permission: 'access content'

    View Slide

  189. namespace Drupal\esi_placeholders\Render\Placeholder;
    use Drupal\big_pipe\Render\Placeholder\BigPipeStrategy;
    use Drupal\Core\Render\Markup;
    use Symfony\Component\HttpFoundation\RequestStack;
    use Symfony\Component\HttpKernel\HttpCache\Esi;
    class EsiStrategy extends BigPipeStrategy
    {
    /**
    * @var RequestStack
    */
    protected $requestStack;
    /**
    * @var Esi
    */
    protected $esi;
    /**
    * EsiStrategy constructor.
    * @param RequestStack $request_stack
    * @param Esi $esi
    */
    public function __construct(RequestStack $request_stack, Esi $esi)
    {
    $this->requestStack = $request_stack;
    $this->esi = $esi;
    }
    /**

    View Slide

  190. /**
    * @param array $placeholders
    * @return array
    */
    public function processPlaceholders(array $placeholders)
    {
    $request = $this->requestStack->getCurrentRequest();
    $overridenPlaceHolder = [];
    foreach ($placeholders as $placeholder => $placeholder_elements) {
    if (isset($placeholder_elements['#lazy_builder']) && $this->esi->hasSurrogateCapability($request)) {
    $overridenPlaceHolder[$placeholder] = [
    '#markup' =>
    Markup::create(
    $this->esi->renderIncludeTag(
    '/esi/block/?'.
    $this->generateBigPipePlaceholderId($placeholder,$placeholder_elements),
    null,
    false
    )
    )
    ];
    }
    }
    return $overridenPlaceHolder;
    }
    }

    View Slide

  191. namespace Drupal\esi_placeholders\Controller;
    use Drupal\Core\Cache\CacheableMetadata;
    use Drupal\Core\Cache\CacheableResponse;
    use Drupal\Core\Controller\ControllerBase;
    use Symfony\Component\HttpFoundation\Request;
    class EsiController extends ControllerBase
    {
    public function returnEsiBlockContent(Request $request)
    {
    $build = [
    'esiBlockContent' => [
    '#lazy_builder' => [
    $request->get('callback'),
    $request->get('args'),
    ]
    ]
    ];
    $output = \Drupal::service('renderer')->renderRoot($build);
    $response = new CacheableResponse($output);
    $response->addCacheableDependency(CacheableMetadata::createFromRenderArray($build));
    return $response;
    }
    }

    View Slide

  192. namespace Drupal\esi_placeholders\EventSubscriber;
    use Symfony\Component\HttpKernel\Event\FilterResponseEvent;
    use Symfony\Component\HttpKernel\HttpCache\Esi;
    use Symfony\Component\HttpKernel\KernelEvents;
    use Symfony\Component\EventDispatcher\EventSubscriberInterface;
    class EsiSubscriber implements EventSubscriberInterface
    {
    /**
    * @var Symfony\Component\HttpKernel\HttpCache\Esi
    */
    protected $esi;
    /**
    * @param Symfony\Component\HttpKernel\HttpCache\Esi $esi
    */
    public function __construct(Esi $esi)
    {
    $this->esi = $esi;
    }
    /**
    * @param FilterResponseEvent $event
    * @return \Symfony\Component\HttpFoundation\Response
    */

    View Slide

  193. /**
    * @param FilterResponseEvent $event
    * @return \Symfony\Component\HttpFoundation\Response
    */
    public function onRespond(FilterResponseEvent $event)
    {
    $request = $event->getRequest();
    $response = $event->getResponse();
    if($this->esi->hasSurrogateCapability($request)){
    $this->esi->addSurrogateControl($response);
    return $response;
    }
    }
    /**
    * {@inheritdoc}
    */
    public static function getSubscribedEvents()
    {
    $events[KernelEvents::RESPONSE][] = ['onRespond', -10000];
    return $events;
    }
    }

    View Slide

  194. https://github.com/ThijsFeryn/drupal8_esi_placeholders

    View Slide

  195. Breaking news isn't breaking

    View Slide

  196. Purging

    View Slide

  197. acl purgers {
    "localhost";
    "127.0.0.1";
    "::1";
    }
    sub vcl_recv {
    if (req.method == "PURGE") {
    if (client.ip !~ purgers) {
    return (synth(405, "Method not allowed"));
    }
    return (purge);
    }
    }
    Purging

    View Slide

  198. Purging
    curl -XPURGE "http://example.com/products"
    Immediately
    remove from
    memory

    View Slide

  199. acl purge {
    "localhost";
    "127.0.0.1";
    "::1";
    }
    sub vcl_recv {
    if (req.method == "PURGE") {
    if (client.ip !~ purgers) {
    return (synth(405, "Method not allowed"));
    }
    if(req.http.x-purge-regex) {
    ban("req.http.host == " + req.http.host + " && req.url ~ " + req.http.x-purge-regex);
    } else {
    ban("req.http.host == " + req.http.host + " && req.url == " + req.url);
    }
    return (synth(200, "Purged"));
    }
    }
    Banning

    View Slide

  200. Banning
    curl -XPURGE "http://example.com/products"
    curl -XPURGE -H "x-purge-regex:/products" "http://example.com"
    Add to ban list, remove
    on next request
    Remove patterns via
    “X-PURGE-REGEX”

    View Slide

  201. Lurker-friendly bans

    View Slide

  202. Ban lurker
    Object
    User
    Varnish
    Server
    Sends HTTP
    response
    Response
    stored in
    object
    Sends BAN to
    Varnish
    Ban lurker
    thread
    Ban list
    Reads
    ban list
    Removes
    object
    ban req.http.host == localhost && req.url ~ /products

    View Slide

  203. Ban lurker
    ban req.http.host == localhost && req.url ~ /products
    Lurker can’t match
    request info
    Lurker can only
    match what’s in the
    object
    Next visitor
    triggers cache
    remove

    View Slide

  204. acl purge {
    "localhost";
    "127.0.0.1";
    "::1";
    }
    sub vcl_recv {
    if (req.method == "PURGE") {
    if (client.ip !~ purgers) {
    return (synth(405, "Method not allowed"));
    }
    if(req.http.x-purge-regex) {
    ban("obj.http.x-host == " + req.http.host + " && obj.http.x-url ~ " + req.http.x-purge-regex);
    } else {
    ban("obj.http.host == " + req.http.host + " && obj.http.x-url == " + req.url);
    }
    return (synth(200, "Purged"));
    }
    }
    sub vcl_backend_response {
    set beresp.http.x-url = bereq.url;
    set beresp.http.x-host = bereq.http.host;
    }
    sub vcl_deliver {
    unset resp.http.x-url;
    unset resp.http.x-host;
    }
    Lurker-friendly bans
    Store request info
    in response object

    View Slide

  205. Lurker-friendly bans
    ban obj.http.x-host == localhost && obj.http.x-url ~ /products
    Lurker can match
    response info
    Ban lurker
    removes item from
    cache async

    View Slide

  206. Banning
    through
    Varnishadm

    View Slide

  207. varnishadm> ban obj.http.x-host == localhost && obj.http.x-url ~ /products
    Varnishadm banning

    View Slide

  208. Banning
    through
    socket

    View Slide

  209. Varnishadm is a
    binary on top of
    the socket

    View Slide

  210. Varnishadm uses
    the secret file to
    authenticate
    automatically

    View Slide

  211. $ telnet varnish 6082
    Connected to localhost.
    Escape character is '^]'.
    107 59
    cohvooigdtqvkpwewhdxkqiwkfkpwsly
    Authentication required.
    auth 5a9c5722f31cc3c92f0e4616571624df7bddde2f8e42aaffe795dc80fb8c91dd
    200 240
    -----------------------------
    Varnish Cache CLI 1.0
    -----------------------------
    Linux,4.9.49-moby,x86_64,-junix,-smalloc,-smalloc,-hcritbit
    varnish-5.2.0 revision 4c4875cbf
    Type 'help' for command list.
    Type 'quit' to close CLI session.
    ban obj.http.x-host == localhost && obj.http.x-url ~ /products
    200 0

    View Slide

  212. $challenge = $argv[1];
    $secret = trim(fgets(STDIN));
    $pack = $challenge . "\x0A" . $secret . "\x0A" . $challenge . "\x0A";
    $key = hash('sha256', $pack);
    echo $key.PHP_EOL;
    Use secret & process challenge
    cohvooigdtqvkpwewhdxkqiwkfkpwsly
    5a9c5722f31cc3c92f0e4616571624df7bddde2f8e42aaffe795dc80fb8c91dd
    E29F6DE6-3803-449E-8A01-AA537A8715B1

    View Slide

  213. $ telnet varnish 6082
    Connected to localhost.
    Escape character is '^]'.
    107 59
    cohvooigdtqvkpwewhdxkqiwkfkpwsly
    Authentication required.
    auth 5a9c5722f31cc3c92f0e4616571624df7bddde2f8e42aaffe795dc80fb8c91dd
    200 240
    -----------------------------
    Varnish Cache CLI 1.0
    -----------------------------
    Linux,4.9.49-moby,x86_64,-junix,-smalloc,-smalloc,-hcritbit
    varnish-5.2.0 revision 4c4875cbf
    Type 'help' for command list.
    Type 'quit' to close CLI session.
    ban obj.http.x-host == localhost && obj.http.x-url ~ /products
    200 0

    View Slide

  214. Secure your access the the admin socket

    View Slide

  215. DAEMON_OPTS="-j unix,user=www-data \
    -a :80 \
    -a :81,PROXY \
    -T localhost:6082 \
    -f /etc/varnish/default.vcl \
    -S /etc/varnish/secret \
    -l 100m,10m \
    -t 60 \
    -p feature=+esi_disable_xml_check \
    -p connect_timeout=20s \
    -p first_byte_timeout=100s \
    -p between_bytes_timeout=5s \
    -s malloc,3g"

    View Slide

  216. View Slide

  217. ✓purge
    ✓purge_purger_http
    Required modules

    View Slide

  218. View Slide

  219. View Slide

  220. View Slide

  221. View Slide

  222. # Only allow BAN requests from IP addresses in the 'purge' ACL.
    if (req.method == "BAN") {
    # Same ACL check as above:
    if (!client.ip ~ purge) {
    return (synth(403, "Not allowed."));
    }
    if (req.http.Purge-Cache-Tags) {
    ban("obj.http.Purge-Cache-Tags ~ " + req.http.Purge-Cache-Tags);
    }
    else {
    return (synth(403, "Purge-Cache-Tags header missing."));
    }
    # Throw a synthetic page so the request won't go to the backend.
    return (synth(200, "Ban added."));
    }

    View Slide

  223. acl purge {
    "127.0.0.1";
    }

    View Slide

  224. Purge-Cache-Tags: block:the_date_time block_view
    config:block.block.bartik_account_menu config:block.block.bartik_branding
    config:block.block.bartik_breadcrumbs config:block.block.bartik_content
    config:block.block.bartik_footer config:block.block.bartik_help
    config:block.block.bartik_local_actions
    config:block.block.bartik_local_tasks config:block.block.bartik_main_menu
    config:block.block.bartik_messages config:block.block.bartik_page_title
    config:block.block.bartik_powered config:block.block.bartik_search
    config:block.block.bartik_tools config:block.block.thedateandtimeblock
    config:block_list config:color.theme.bartik config:filter.format.basic_html
    config:search.settings config:system.menu.account config:system.menu.footer
    config:system.menu.main config:system.menu.tools config:system.site
    config:user.role.anonymous config:views.view.frontpage http_response node:1
    node:2 node_list node_view rendered user:1

    View Slide

  225. https://feryn.eu
    https://twitter.com/ThijsFeryn
    https://instagram.com/ThijsFeryn

    View Slide

  226. View Slide

  227. View Slide

  228. sub vcl_backend_response {
    set beresp.grace = 6h;
    }
    Grace mode
    Monitoring & logging

    View Slide

  229. Varnishstat
    Realtime
    statistics

    View Slide

  230. View Slide

  231. usage: varnishstat [-1lV] [-f field] [-t seconds|] [-n varnish_name] [-N filename]
    -1 # Print the statistics to stdout.
    -f field # Field inclusion glob
    # If it starts with '^' it is used as an exclusion list.
    -l # Lists the available fields to use with the -f option.
    -n varnish_name # The varnishd instance to get logs from.
    -N filename # Filename of a stale VSM instance.
    -t seconds| # Timeout before returning error on initial VSM connection.
    -V # Display the version number and exit.
    -x # Print statistics to stdout as XML.
    -j # Print statistics to stdout as JSON.
    Varnishstat usage

    View Slide

  232. ~# varnishstat -f MAIN.cache_hit -1
    MAIN.cache_hit 13049135 5.39 Cache hits
    Varnishstat usage
    ~# varnishstat -f MAIN.cache_hit -j -1
    {
    "timestamp": "2016-06-14T16:10:32",
    "MAIN.cache_hit": {
    "description": "Cache hits",
    "type": "MAIN", "flag": "c", "format": "i",
    "value": 13050992
    }
    }

    View Slide

  233. Varnishstat usage
    ~# varnishstat -f MAIN.n_object -f MAIN.n_lru_nuked -j
    {
    "timestamp": "2016-06-14T16:14:49",
    "MAIN.n_object": {
    "description": "object structs made",
    "type": "MAIN", "flag": "g", "format": "i",
    "value": 46295
    },
    "MAIN.n_lru_nuked": {
    "description": "Number of LRU nuked objects",
    "type": "MAIN", "flag": "g", "format": "i",
    "value": 0
    }
    }

    View Slide

  234. varnishstat -f MAIN.cache*

    View Slide

  235. ✓ Session
    ✓ Client
    ✓ Uptime
    ✓ Hit/miss
    ✓ Backend
    ✓ Fetch
    ✓ Threading
    ✓ Cache
    objects
    ✓ Memory
    ✓ Invalidation
    Varnishstat counters

    View Slide

  236. VSL

    View Slide

  237. Varnish
    Shared memory
    Logging

    View Slide

  238. ✓ In-memory logs
    ✓ Generated by varnishd
    ✓ 81 MB by default
    ✓ Customize with “-l” setting
    ✓ Varnishlog command
    ✓ Varnishtop command
    VSL

    View Slide

  239. * << Request >> 10973258
    - Begin req 10973257 rxreq
    - Timestamp Start: 1501507281.942533 0.000000 0.000000
    - Timestamp Req: 1501507281.942533 0.000000 0.000000
    - ReqStart 127.0.0.1 59753
    - ReqMethod GET
    - ReqURL /
    - ReqProtocol HTTP/1.1
    - ReqHeader Host: feryn.eu

    View Slide

  240. Transactions

    View Slide

  241. ✓ Items of work
    ✓ Identified by VXID
    ✓ 2 kinds:
    ✓ Sessions
    ✓ Requests
    Transactions

    View Slide

  242. ✓ Identifies TCP
    connection
    ✓ Contains multiple
    requests
    Transactions
    ✓ Client request
    ✓ Backend request
    ✓ ESI subrequest
    Session Request

    View Slide

  243. View Slide

  244. ✓ VXID (default)
    ✓ Session
    ✓ Request
    ✓ Raw
    Transactions grouping

    View Slide

  245. Example
    composition that will
    be monitored

    View Slide

  246. varnishlog -i Begin,ReqUrl,Link,BereqURL

    View Slide

  247. * << BeReq >> 98318
    - Begin bereq 98317 fetch
    - BereqURL /
    * << BeReq >> 98320
    - Begin bereq 98319 fetch
    - BereqURL /header
    * << Request >> 98319
    - Begin req 98317 esi
    - ReqURL /header
    - Link bereq 98320 fetch
    * << BeReq >> 98322
    - Begin bereq 98321 fetch
    - BereqURL /nav
    * << Request >> 98321
    - Begin req 98317 esi
    - ReqURL /nav
    - Link bereq 98322 fetch
    * << Request >> 98317
    - Begin req 98316 rxreq
    - ReqURL /
    - Link bereq 98318 fetch
    - Link req 98319 esi
    - Link req 98321 esi
    * << BeReq >> 98324
    - Begin bereq 98323 fetch
    - BereqURL /footer
    * << Request >> 98323
    - Begin req 98316 rxreq
    - ReqURL /footer
    - Link bereq 98324 fetch
    * << Session >> 98316
    - Begin sess 0 HTTP/1
    - Link req 98317 rxreq
    - Link req 98323 rxreq

    View Slide

  248. varnishlog -i Begin,ReqUrl,Link,BereqURL -g session

    View Slide

  249. * << Session >> 14
    - Begin sess 0 HTTP/1
    - Link req 65539 rxreq
    - Link req 65545 rxreq
    ** << Request >> 65539
    -- Begin req 14 rxreq
    -- ReqURL /
    -- Link bereq 65540 fetch
    -- Link req 65541 esi
    -- Link req 65543 esi
    ** << Request >> 65545
    -- Begin req 14 rxreq
    -- ReqURL /footer
    -- Link bereq 65546 fetch
    *** << BeReq >> 65540
    --- Begin bereq 65539 fetch
    --- BereqURL /
    *** << Request >> 65541
    --- Begin req 65539 esi
    --- ReqURL /header
    --- Link bereq 65542 fetch
    *** << Request >> 65543
    --- Begin req 65539 esi
    --- ReqURL /nav
    --- Link bereq 65544 fetch
    *** << BeReq >> 65546
    --- Begin bereq 65545 fetch
    --- BereqURL /footer
    **** << BeReq >> 65542
    ---- Begin bereq 65541 fetch
    ---- BereqURL /header
    **** << BeReq >> 65544
    ---- Begin bereq 65543 fetch
    ---- BereqURL /nav

    View Slide

  250. View Slide

  251. Tags

    View Slide

  252. Request tags

    View Slide

  253. ✓ ReqMethod
    ✓ ReqUrl
    ✓ ReqProtocol
    ✓ ReqHeader
    Request tags

    View Slide

  254. - ReqStart 127.0.0.1 56312
    - ReqMethod GET
    - ReqURL /
    - ReqProtocol HTTP/1.1
    - ReqHeader Host: localhost
    - ReqHeader Connection: keep-alive
    - ReqHeader Upgrade-Insecure-Requests: 1
    - ReqHeader User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X
    10_12_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/
    59.0.3071.115 Safari/537.36
    - ReqHeader Accept: text/html,application/xhtml+xml,application/
    xml;q=0.9,image/webp,image/apng,*/*;q=0.8
    - ReqHeader Accept-Encoding: gzip, deflate, br
    - ReqHeader Accept-Language: nl,en-US;q=0.8,en;q=0.6
    - ReqHeader X-Forwarded-For: 127.0.0.1

    View Slide

  255. Response tags

    View Slide

  256. ✓ RespProtocol
    ✓ RespStatus
    ✓ RespReason
    ✓ RespHeader
    Response tags

    View Slide

  257. - RespProtocol HTTP/1.1
    - RespStatus 200
    - RespReason OK
    - RespHeader Host: localhost
    - RespHeader Cache-Control: public, s-maxage=500
    - RespHeader Date: Tue, 01 Aug 2017 08:56:44 GMT
    - RespHeader ETag: "c5afddc587599a72d467caca23e980bf"
    - RespHeader Vary: Accept-Language
    - RespHeader Content-Length: 3098
    - RespHeader Content-Type: text/html; charset=UTF-8
    - RespHeader X-Varnish: 32770
    - RespHeader Age: 10

    View Slide

  258. Backend tags

    View Slide

  259. - BackendOpen 19 boot.default 127.0.0.1 8080 127.0.0.1 62552
    - BackendClose 19 boot.default

    View Slide

  260. Backend request tags

    View Slide

  261. ✓ BereqMethod
    ✓ BereqUrl
    ✓ BereqProtocol
    ✓ BereqHeader
    Backend request tags

    View Slide

  262. Backend response
    tags

    View Slide

  263. ✓ BerespProtocol
    ✓ BerespStatus
    ✓ BerespReason
    ✓ BerespHeader
    Backens response tags

    View Slide

  264. Object tags

    View Slide

  265. ✓ ObjProtocol
    ✓ ObjStatus
    ✓ ObjReason
    ✓ ObjHeader
    Object tags

    View Slide

  266. VCL tags

    View Slide

  267. ✓ VCL_Call
    ✓ VCL_Return
    ✓ VCL_Error
    ✓ VCL_Log
    ✓ VCL_Acl
    VCL tags

    View Slide

  268. * << Request >> 5
    - ReqURL /
    - VCL_call RECV
    - VCL_return hash
    - VCL_call HASH
    - VCL_return lookup
    - VCL_call MISS
    - VCL_return fetch
    - VCL_call DELIVER
    - VCL_return deliver
    ** << BeReq >> 6
    -- BereqURL /
    -- VCL_call BACKEND_FETCH
    -- VCL_return fetch
    -- VCL_call BACKEND_RESPONSE
    -- VCL_return deliver

    View Slide

  269. * << Request >> 6
    - ReqURL /
    - VCL_call RECV
    - ReqURL /
    - VCL_return hash
    - VCL_call HASH
    - VCL_return lookup
    - VCL_call HIT
    - VCL_return deliver
    - VCL_call DELIVER
    - VCL_return deliver

    View Slide

  270. * << Request >> 32789
    - ReqURL /header
    - ExpBan 98355 banned lookup
    ExpBan tag

    View Slide

  271. * << Request >> 98369
    - ReqURL /footer
    - Hit 65597
    Hit tag
    varnishlog -i "ReqUrl,Hit"

    View Slide

  272. ** << Request >> 6
    -- ReqURL /footer
    -- HitPass 3
    HitPass tag

    View Slide

  273. TTL tag

    View Slide

  274. %s %d %d %d %d [ %d %d %u %u ]
    | | | | | | | | |
    | | | | | | | | +- Max-Age from Cache-Control header
    | | | | | | | +---- Expires header
    | | | | | | +------- Date header
    | | | | | +---------- Age (incl Age: header value)
    | | | | +--------------- Reference time for TTL
    | | | +------------------ Keep
    | | +--------------------- Grace
    | +------------------------ TTL
    +--------------------------- "RFC" or "VCL"
    TTL tag

    View Slide

  275. -- TTL VCL 120 10 0 1501597242
    ✓ TTL decided by the VCL
    ✓ 120 seconds cached
    ✓ 10 seconds grace time
    ✓ 0 seconds keep time
    ✓ Reference time: 1501597242

    (2017-08-01 14:20:42)

    View Slide

  276. -- RFC 500 10 -1 1501598872 1501598872 1501598872 0 500
    ✓ 500 seconds TTL (via headers)
    ✓ 10 seconds grace
    ✓ No keep value
    ✓ 2017-08-01 14:47:52 date, age & reference time
    ✓ Cache-control headers sets 500 second TTL

    View Slide

  277. -- RFC 500 10 -1 1501598872 1501598869 1501598872 0 500
    ✓ Don’t screw with the age header
    ✓ Only 497 second effective TTL
    ✓ Custom Age header (3 seconds off)

    View Slide

  278. Begin tag

    View Slide

  279. - Begin bereq 98317 fetch
    - Begin req 98317 esi
    - Begin req 98316 rxreq
    - Begin sess 0 HTTP/1

    View Slide

  280. Link tag

    View Slide

  281. - Link bereq 98312 fetch
    - Link req 98311 rxreq
    - Link req 98318 esi

    View Slide

  282. Timestamp tag

    View Slide

  283. %s: %f %f %f
    | | | |
    | | | +- Time since last timestamp
    | | +---- Time since start of work unit
    | +------- Absolute time of event
    +----------- Event label
    Timestamp tag

    View Slide

  284. * << Request >> 65539
    - Timestamp Start: 1501601912.758662 0.000000 0.000000
    - Timestamp Req: 1501601912.758662 0.000000 0.000000
    - Timestamp Fetch: 1501601912.806733 0.048071 0.048071
    - Timestamp Process: 1501601912.806750 0.048088 0.000017
    - Timestamp Resp: 1501601912.806787 0.048125 0.000037
    ** << BeReq >> 65540
    -- Timestamp Start: 1501601912.758753 0.000000 0.000000
    -- Timestamp Bereq: 1501601912.758952 0.000199 0.000199
    -- Timestamp Beresp: 1501601912.806677 0.047924 0.047725
    -- Timestamp BerespBody: 1501601912.806749 0.047996 0.000072

    View Slide

  285. Filtering output

    View Slide

  286. ✓ -i: include tags
    ✓ -I: include tags by regex
    ✓ -x: exclude tags
    ✓ -X: exclude by regex
    Filtering output

    View Slide

  287. Include tags

    View Slide

  288. varnishlog -i ReqUrl,VCL_call,VCL_return -g session
    varnishlog -i "ReqUrl,VCL_*" -g session

    View Slide

  289. * << Session >> 252394
    ** << Request >> 252395
    -- ReqURL /
    -- VCL_call RECV
    -- VCL_return hash
    -- VCL_call HASH
    -- VCL_return lookup
    -- VCL_call HIT
    -- VCL_return deliver
    -- VCL_call DELIVER
    -- VCL_return deliver
    *** << Request >> 252397
    --- ReqURL /header
    --- VCL_call RECV
    --- VCL_return hash
    --- VCL_call HASH
    --- VCL_return lookup
    --- VCL_call HIT
    --- VCL_return deliver
    --- VCL_call DELIVER
    --- VCL_return deliver
    *** << Request >> 252399
    --- ReqURL /nav
    --- VCL_call RECV
    --- VCL_return hash
    --- VCL_call HASH
    --- VCL_return lookup
    --- VCL_call HIT
    --- VCL_return deliver
    --- VCL_call DELIVER
    --- VCL_return deliver
    *** << BeReq >> 252396
    --- VCL_call BACKEND_FETCH
    --- VCL_return fetch
    --- VCL_call BACKEND_RESPONSE
    --- VCL_return deliver
    **** << BeReq >> 252398
    ---- VCL_call BACKEND_FETCH
    ---- VCL_return fetch
    ---- VCL_call BACKEND_RESPONSE
    ---- VCL_return deliver
    **** << BeReq >> 252400
    ---- VCL_call BACKEND_FETCH
    ---- VCL_return fetch
    ---- VCL_call BACKEND_RESPONSE
    ---- VCL_return deliver

    View Slide

  290. Exclude tags

    View Slide

  291. varnishlog -i "Req*" -x ReqHeader,ReqUnset

    View Slide

  292. * << Request >> 314125
    - ReqStart 127.0.0.1 64585
    - ReqMethod GET
    - ReqURL /
    - ReqProtocol HTTP/1.1
    - ReqAcct 476 0 476 311 0 311
    * << Request >> 314126
    - ReqStart 127.0.0.1 64585
    - ReqMethod GET
    - ReqURL /footer
    - ReqProtocol HTTP/1.1
    - ReqAcct 370 0 370 309 0 309

    View Slide

  293. Include tags by regex

    View Slide

  294. varnishlog -I "reqheader:Accept-Language" -i requrl

    View Slide

  295. * << Request >> 374378
    - ReqURL /
    - ReqHeader Accept-Language: nl,en-US;q=0.8,en;q=0.6
    * << Request >> 374379
    - ReqURL /footer
    - ReqHeader Accept-Language: nl,en-US;q=0.8,en;q=0.6

    View Slide

  296. Exclude tags by regex

    View Slide

  297. * << Request >> 374384
    - ReqURL /footer
    - RespHeader Host: localhost
    - RespHeader X-Powered-By: PHP/7.0.15
    - RespHeader Cache-Control: public, s-maxage=500
    - RespHeader Date: Wed, 02 Aug 2017 11:27:21 GMT
    - RespHeader ETag: "d47ac09f5351f8f4c97c99ef5b3d2ecd"
    - RespHeader Vary: Accept-Language
    - RespHeader Content-Length: 80
    - RespHeader Content-Type: text/html; charset=UTF-8
    - RespHeader X-Varnish: 374384 15367
    - RespHeader Age: 334
    - RespHeader Via: 1.1 varnish-v4
    - RespHeader Connection: keep-alive

    View Slide

  298. varnishlog -i RespHeader,ReqUrl -X "RespHeader:(x|X)-"

    View Slide

  299. * << Request >> 374384
    - ReqURL /footer
    - RespHeader Host: localhost
    - RespHeader Cache-Control: public, s-maxage=500
    - RespHeader Date: Wed, 02 Aug 2017 11:27:21 GMT
    - RespHeader ETag: "d47ac09f5351f8f4c97c99ef5b3d2ecd"
    - RespHeader Vary: Accept-Language
    - RespHeader Content-Length: 80
    - RespHeader Content-Type: text/html; charset=UTF-8
    - RespHeader Age: 334
    - RespHeader Via: 1.1 varnish-v4
    - RespHeader Connection: keep-alive

    View Slide

  300. All-in-one

    View Slide

  301. varnishlog -i "RespHeader,Req*" -X "RespHeader:(x|X)-" -I
    "timestamp:Resp" -x reqprotocol,reqacct -g request

    View Slide

  302. * << Request >> 59383
    - ReqStart 127.0.0.1 53195
    - ReqMethod GET
    - ReqURL /
    - ReqHeader Host: localhost
    - ReqHeader Connection: keep-alive
    - ReqHeader Cache-Control: max-age=0
    - ReqHeader Upgrade-Insecure-Requests:
    1
    - ReqHeader User-Agent: Mozilla/5.0
    (Macintosh; Intel Mac OS X 10_12_5)
    AppleWebKit/537.36 (KHTML, like Gecko)
    Chrome/59.0.3071.115 Safari/537.36
    - ReqHeader Accept: text/
    html,application/
    xhtml+xml,application/xml;q=0.9,image/
    webp,image/apng,*/*;q=0.8
    - ReqHeader Accept-Encoding: gzip,
    deflate, br
    - ReqHeader Accept-Language: nl,en-
    US;q=0.8,en;q=0.6
    - ReqHeader If-None-Match:
    W/"27f341f8e459dd35f1087c55351cacda"
    - ReqHeader X-Forwarded-For: 127.0.0.1
    - ReqUnset Accept-Language: nl,en-
    US;q=0.8,en;q=0.6
    - ReqHeader accept-language: nl
    - ReqHeader Surrogate-Capability:
    key=ESI/1.0
    - ReqUnset Accept-Encoding: gzip,
    deflate, br
    - ReqHeader Accept-Encoding: gzip
    - RespHeader Host: localhost
    - RespHeader Cache-Control: public, s-
    maxage=500
    - RespHeader Date: Wed, 02 Aug 2017
    11:46:49 GMT
    - RespHeader ETag:
    "27f341f8e459dd35f1087c55351cacda"
    - RespHeader Vary: Accept-Language
    - RespHeader Content-Length: 3098
    - RespHeader Content-Type: text/html;
    charset=UTF-8
    - RespHeader Age: 152
    - RespHeader Via: 1.1 varnish-v4
    - RespHeader ETag:
    W/"27f341f8e459dd35f1087c55351cacda"
    - RespHeader Connection: keep-alive
    - Timestamp Resp: 1501674561.472358
    0.000068 0.000020

    View Slide

  303. ✓ All response headers
    ✓ All tags that start with “Req”
    ✓ Exclude “x-“ response headers
    ✓ Include “response time” timestamp
    ✓ Exclude request protocol log lines,
    and the request accountancy log
    lines
    All-in-one

    View Slide

  304. VSL queries

    View Slide

  305. Filtering fields from
    all transactions
    Filtering transactions

    View Slide


  306. {level}taglist:record-prefix[field]

    View Slide

  307. ReqUrl eq ‘/‘
    {level}taglist:record-prefix[field]

    View Slide

  308. Timestamp:Resp[2] > 1.0
    {level}taglist:record-prefix[field]

    View Slide

  309. {2}Timestamp:Resp[2] > 1.0
    {level}taglist:record-prefix[field]

    View Slide

  310. varnishlog -i VCL_call,VCL_return -g request -q "ReqURL eq '/'"

    View Slide

  311. * << Request >> 374400
    - VCL_call RECV
    - VCL_return hash
    - VCL_call HASH
    - VCL_return lookup
    - VCL_call HIT
    - VCL_return deliver
    - VCL_call DELIVER
    - VCL_return deliver

    View Slide

  312. varnishlog -i ReqUrl -q "VCL_call eq 'MISS' or VCL_call eq 'PASS'"
    varnishlog -i ReqUrl -I "Timestamp:Resp" -q "Timestamp:Resp[2] > 1.0"

    View Slide

  313. Other options

    View Slide

  314. varnishlog -n myVarnishInstance
    varnishlog -d
    varnishlog -w file
    varnishlog -r file
    varnishlog -A -a -w file
    varnishlog -i "ReqUrl,VCL_*" -D -a -A -w /var/log/varnish/custom.log -
    P /var/run/custom_varnishlog.pid

    View Slide

  315. Varnishtop

    View Slide

  316. Same syntax as varnishlog.
    Output is incremental

    View Slide

  317. $ varnishtop -I reqheader:Accept-Language -q "ReqUrl eq '/'"
    list length 4
    0.86 ReqHeader Accept-Language: en-US
    0.80 ReqHeader Accept-Language: nl-NL,nl;q=0.8,en-
    US;q=0.6,en;q=0.4
    0.54 ReqHeader Accept-Language: nl,en-US;q=0.8,en;q=0.6
    0.39 ReqHeader Accept-Language: nl-BE

    View Slide

  318. Common Varnishlog
    scenarios

    View Slide

  319. Why didn’t Varnish serve this request from cache?

    View Slide

  320. Request not
    cacheable

    View Slide

  321. varnishlog -i "Req*,VCL*" -x ReqAcct,ReqStart -q "VCL_call
    eq 'PASS'"

    View Slide

  322. * << Request >> 12
    - ReqMethod GET
    - ReqURL /
    - ReqProtocol HTTP/1.1
    - ReqHeader Host: localhost
    - ReqHeader User-Agent: curl/7.48.0
    - ReqHeader Accept: */*
    - ReqHeader Cookie: myCookie=bla
    - ReqHeader X-Forwarded-For: 127.0.0.1
    - VCL_call RECV
    - VCL_return pass
    - VCL_call HASH
    - VCL_return lookup
    - VCL_call PASS
    - VCL_return fetch
    - VCL_call DELIVER
    - VCL_return deliver

    View Slide

  323. << Request >> 32779
    - ReqMethod POST
    - ReqURL /
    - ReqProtocol HTTP/1.1
    - ReqHeader Host: localhost
    - ReqHeader User-Agent: curl/7.48.0
    - ReqHeader Accept: */*
    - ReqHeader X-Forwarded-For: 127.0.0.1
    - VCL_call RECV
    - VCL_return pass
    - VCL_call HASH
    - VCL_return lookup
    - VCL_call PASS
    - VCL_return fetch
    - VCL_call DELIVER
    - VCL_return deliver

    View Slide

  324. * << Request >> 15
    - ReqMethod GET
    - ReqURL /
    - ReqProtocol HTTP/1.1
    - ReqHeader Host: localhost
    - ReqHeader Authorization: Basic dGhpanM6ZmVyeW4=
    - ReqHeader User-Agent: curl/7.48.0
    - ReqHeader Accept: */*
    - ReqHeader X-Forwarded-For: 127.0.0.1
    - VCL_call RECV
    - VCL_return pass
    - VCL_call HASH
    - VCL_return lookup
    - VCL_call PASS
    - VCL_return fetch
    - VCL_call DELIVER
    - VCL_return deliver

    View Slide

  325. Response not
    cacheable

    View Slide

  326. varnishlog -i ReqUrl,VCL_*,Beresp*,TTL -q "HitPass" -g
    request

    View Slide

  327. * << Request >> 19010384
    - ReqURL /my-url
    - VCL_call RECV
    - VCL_return hash
    - VCL_call HASH
    - VCL_return lookup
    - VCL_call PASS
    - VCL_return fetch
    - VCL_call DELIVER
    - VCL_return deliver
    ** << BeReq >> 19010385
    -- VCL_call BACKEND_FETCH
    -- VCL_return fetch
    -- BerespProtocol HTTP/1.1
    -- BerespStatus 200
    -- BerespReason OK
    -- BerespHeader Date: Thu, 03 Aug
    2017 08:15:22 GMT
    -- BerespHeader Server: Apache/
    2.4.10 (Debian)
    -- BerespHeader Last-Modified: Tue,
    01 Aug 2017 07:21:00 GMT
    -- BerespHeader ETag:
    "5c0d-555abfd3f422f-gzip"
    -- BerespHeader Vary: Accept-
    Encoding
    -- BerespHeader Content-Encoding:
    gzip
    -- BerespHeader Cache-Control: max-
    age=0
    -- BerespHeader Expires: Thu, 03 Aug
    2017 08:15:22 GMT
    -- BerespHeader Content-Length: 7686
    -- BerespHeader Content-Type:
    application/json
    -- TTL RFC 0 10 -1 1501748123
    1501748123 1501748122 1501748122 0
    -- VCL_call BACKEND_RESPONSE
    -- TTL VCL 120 10 0 1501748123
    -- VCL_return deliver

    View Slide

  328. * << Request >> 65551
    - ReqURL /set-cookie
    - VCL_call RECV
    - VCL_return hash
    - VCL_call HASH
    - VCL_return lookup
    - VCL_call PASS
    - VCL_return fetch
    - VCL_call DELIVER
    - VCL_return deliver
    ** << BeReq >> 65552
    -- VCL_call BACKEND_FETCH
    -- VCL_return fetch
    -- BerespProtocol HTTP/1.1
    -- BerespStatus 200
    -- BerespReason OK
    -- BerespHeader Cache-control: s-maxage=10
    -- BerespHeader Set-Cookie: myCookie=bla
    -- BerespHeader Content-type: text/html; charset=UTF-8
    -- BerespHeader Date: Thu, 03 Aug 2017 08:39:04 GMT
    -- TTL RFC 10 10 -1 1501749545 1501749545 1501749544 0 10
    -- VCL_call BACKEND_RESPONSE
    -- TTL VCL 120 10 0 1501749545
    -- VCL_return deliver

    View Slide

  329. https://feryn.eu
    https://twitter.com/ThijsFeryn
    https://instagram.com/ThijsFeryn

    View Slide

  330. View Slide