Varnish workshop - Drupal Europe 2018

Transcript

1. Varnish workshop By Thijs Feryn

2. Slow websites suck

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

4. Slow ~ Down

5. Saturated market

6. None
7. None
8. None
9. None

10. Heavy load

11. Mo money Mo servers

12. Refactor slow code Write fast code

13. After a while you hit the limits

14. Cache

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

16. Caching is not a compensation for poor code

17. Caching is an essential architectural strategy

18. Hi, I’m Thijs

19. I’m @ThijsFeryn on Twitter

20. I’m an Evangelist At

21. I’m an Evangelist At

22. None
23. None

24. Normally User Server

25. With Varnish User Varnish Server

26. None
27. None

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

    ✓ BigPipe ✓ BigPipe sessionless

29. Install & configure

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

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

    install varnish Debian & Ubuntu

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

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

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

    install varnish RHEL & CentOS

35. Config file

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

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"

38. The backend

39. Other port Other IP Other server

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

    to Varnish

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

42. vcl 4.0;
 
 backend default {
 .host = "127.0.0.1";
 .port

    = "8080";
 } In VCL file Minimal VCL

43. What about TLS/SSL?

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

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

    here Public

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

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

48. What’s the real IP?

49. X-Forwarded-For

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

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

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

53. PROXY Protocol

54. Add original IP as TCP preamble

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"

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
57. None

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

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

60. There are rules

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

62. Idempotence Execute multiple times Result doesn't change

63. ✓ GET ✓ HEAD - POST - PUT - DELETE

    - PATCH Idempotence Result changes Result doesn't change Don't cache

64. State

65. State ~ user specific data Cookies Auth headers

66. About cookies

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

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

69. Time To Live

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

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

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

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

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

75. Don’t set the Age header yourself!

76. Conditional requests

77. Only fetch payload that has changed

78. Otherwise: HTTP/1.1 304 Not Modified

79. ✓ Conserve bandwidth ✓ Reduce load on the backend when

    revalidating Conditional requests

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

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

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

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

84. Store etag or modification date

85. Validate early on

86. Exit quickly

87. None

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

89. Varnish can revalidate aynchronously

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

    Not Modified

91. And serve stale data while that happens

92. Grace mode

93. Effective TTL = TTL + grace

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

95. Variations

96. Cache is not the same for everyone

97. ✓ URL ✓ Hostname ✓ IP if hostname is not

    set ✓ Vary header Basic variations

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

99. The flow

100. None
101. None

102. Varnish Configuration Language

103. DSL compiled and linked as shared object

104. /etc/varnish/default.vcl

105. Hooks & subroutines

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

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

108. Actions

109. ✓ hash: lookup in cache ✓ pass: don't cache ✓

     synth: synthetic HTML output ✓ pipe: bypass cache ✓ purge: remove from cache VCL_RECV

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

111. ✓ fetch: fetch data from backend, don't cache ✓ restart:

     restart transaction ✓ synth: synthetic HTML output VCL_PASS

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

113. ✓ fetch: fetch data from backend ✓ pass: fetch data

     from backend, don't cache ✓ restart: restart transaction ✓ synth: synthetic HTML output VCL_MISS

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

     VCL_HASH

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

116. ✓ deliver: deliver object to client ✓ restart: restart transaction

     ✓ synth: synthetic HTML output VCL_DELIVER

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

     transaction VCL_SYNTH

118. ✓ fetch: fetch object from backend ✓ abandon: abandon request

     and send HTTP 503 error VCL_BACKEND_FETCH

119. ✓ deliver: send fetched data to client ✓ abandon: abandon

     request and send HTTP 503 error ✓ retry: retry backend request VCL_BACKEND_RESPONSE

120. ✓ deliver: send fetched data to client ✓ retry: retry

     backend request VCL_BACKEND_ERROR

121. Typical flows

122. ✓ vcl_recv: hash ✓ vcl_hash: lookup ✓ vcl_miss: fetch ✓

     vcl_backend_request: fetch ✓ vcl_backend_response: deliver ✓ vcl_deliver: deliver MISS

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

     vcl_deliver: deliver HIT

124. ✓ vcl_recv: pass ✓ vcl_pass: fetch ✓ vcl_backend_request: fetch ✓

     vcl_backend_response: deliver ✓ vcl_deliver: deliver PASS

125. Objects

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

127. Variables

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

     ✓ … req variables

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

     bereq variables

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

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

     remote variables ✓ remote.ip

132. ✓ obj.age ✓ obj.grace ✓ obj.hits ✓ obj.http.cache-control ✓ obj.reason

     ✓ obj.status ✓ obj.ttl object variables

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

134. Default behaviour

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

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

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

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

     = "5"; synthetic( {"<!DOCTYPE html> <html> <head> <title>"} + resp.status + " " + resp.reason + {"</title> </head> <body> <h1>Error "} + resp.status + " " + resp.reason + {"</h1> <p>"} + resp.reason + {"</p> <h3>Guru Meditation:</h3> <p>XID: "} + req.xid + {"</p> <hr> <p>Varnish cache server</p> </body> </html> "} ); return (deliver); } Send custom HTML

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

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

     = "5"; synthetic( {"<!DOCTYPE html> <html> <head> <title>"} + beresp.status + " " + beresp.reason + {"</title> </head> <body> <h1>Error "} + beresp.status + " " + beresp.reason + {"</h1> <p>"} + beresp.reason + {"</p> <h3>Guru Meditation:</h3> <p>XID: "} + bereq.xid + {"</p> <hr> <p>Varnish cache server</p> </body> </html> "} ); return (deliver); } Send custom HTML on backend error

141. In an ideal world

142. HTTP best practices > custom VCL

143. Reality sucks

144. None
145. None

146. Don’t trust the end-user

147. Cache-control ?

148. Legacy

149. Write VCL

150. Normalize

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

152. Static assets

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

154. Do you really want to cache static assets?

155. Nginx or Apache can be fast enough for that

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

157. Blacklist/whitelist

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

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

     } URL whitelist

160. if (beresp.http.Surrogate-Control ~ "BigPipe/1.0") { set beresp.do_stream = true; set

     beresp.ttl = 0s; } Don't cache BigPipe responses

161. Those damn cookies again!

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

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

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

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

166. Block caching

167. None

168. Code renders single HTTP response

169. Lowest denominator: no cache

170. <esi:include src="/header" /> Edge Side Includes ✓Placeholder ✓Parsed by Varnish

     ✓Output is a composition of blocks ✓State per block ✓TTL per block

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

172. <?php header("Cache-Control: public,must-revalidate,s-maxage=10"); echo "Date in the ESI tag: ".date('Y-m-d

     H:i:s').'<br />'; <?php header("Cache-Control: no-store"); header(“Surrogate-Control: content='ESI/1.0'"); echo '<esi:include src="/esi.php" />'.PHP_EOL; echo "Date in the main page: ".date('Y-m-d H:i:s').'<br />'; Main page ESI frame: esi.php Cached for 10 seconds Not cached

173. ESI_xmlerror No ESI processing, first char not '<'. (See feature

     esi_disable_xml_check) Expects HTML/ XML tags

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

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

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

177. ESI vs AJAX

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

179. ✓ Client-side ✓ Common knowledge ✓ Parallel processing ✓ Graceful

     degradation AJAX - Processed by the browser - Extra roundtrips - Somewhat slower

180. Choose wisely

181. None

182. Auto-placeholdering

183. BigPipe

184. <span data-big-pipe-placeholder- id="callback=Drupal%5CCore%5CRender%5CElem ent%5CStatusMessages%3A%3ArenderMessages&a mp;args%5B0%5D&amp;token=_HAdUpwWmet0TOTe2 PSiJuMntExoshbm1kh2wQzzzAA"></span>

185. <script type="application/vnd.drupal-ajax" data-big-pipe- replacement-for-placeholder-with- id="callback=Drupal%5CCore%5CRender%5CElement%5CStatusMessages%3A%3A renderMessages&amp;args%5B0%5D&amp;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}] </script>

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

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 }

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'

189. <?php 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; } /**

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

191. <?php 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; } }

192. <?php 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 */

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

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

195. Breaking news isn't breaking

196. Purging

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

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

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

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”

201. Lurker-friendly bans

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

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

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

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

206. Banning through Varnishadm

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

     banning

208. Banning through socket

209. Varnishadm is a binary on top of the socket

210. Varnishadm uses the secret file to authenticate automatically

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

212. <?php $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

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

214. Secure your access the the admin socket

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"
216. None

217. ✓purge ✓purge_purger_http Required modules

218. None
219. None
220. None
221. None

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.")); }

223. acl purge { "127.0.0.1"; }

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

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

226. None
227. None

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

     Monitoring & logging

229. Varnishstat Realtime statistics

230. None

231. usage: varnishstat [-1lV] [-f field] [-t seconds|<off>] [-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|<off> # 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

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

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

234. varnishstat -f MAIN.cache*

235. ✓ Session ✓ Client ✓ Uptime ✓ Hit/miss ✓ Backend

     ✓ Fetch ✓ Threading ✓ Cache objects ✓ Memory ✓ Invalidation Varnishstat counters

236. VSL

237. Varnish Shared memory Logging

238. ✓ In-memory logs ✓ Generated by varnishd ✓ 81 MB

     by default ✓ Customize with “-l” setting ✓ Varnishlog command ✓ Varnishtop command VSL

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

240. Transactions

241. ✓ Items of work ✓ Identified by VXID ✓ 2

     kinds: ✓ Sessions ✓ Requests Transactions

242. ✓ Identifies TCP connection ✓ Contains multiple requests Transactions ✓

     Client request ✓ Backend request ✓ ESI subrequest Session Request
243. None

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

     grouping

245. Example composition that will be monitored

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

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

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

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
250. None

251. Tags

252. Request tags

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

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

255. Response tags

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

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

258. Backend tags

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

     19 boot.default

260. Backend request tags

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

     tags

262. Backend response tags

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

     tags

264. Object tags

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

266. VCL tags

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

     VCL tags

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

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

270. * << Request >> 32789 - ReqURL /header - ExpBan

     98355 banned lookup ExpBan tag

271. * << Request >> 98369 - ReqURL /footer - Hit

     65597 Hit tag varnishlog -i "ReqUrl,Hit"

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

     3 HitPass tag

273. TTL tag

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

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)

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

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)

278. Begin tag

279. - Begin bereq 98317 fetch - Begin req 98317 esi

     - Begin req 98316 rxreq - Begin sess 0 HTTP/1

280. Link tag

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

     - Link req 98318 esi

282. Timestamp tag

283. %s: %f %f %f | | | | | |

     | +- Time since last timestamp | | +---- Time since start of work unit | +------- Absolute time of event +----------- Event label Timestamp tag

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

285. Filtering output

286. ✓ -i: include tags ✓ -I: include tags by regex

     ✓ -x: exclude tags ✓ -X: exclude by regex Filtering output

287. Include tags

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

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

290. Exclude tags

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

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

293. Include tags by regex

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

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

296. Exclude tags by regex

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

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

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

300. All-in-one

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

     request

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

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

304. VSL queries

305. Filtering fields from all transactions Filtering transactions

306. <record selection criteria> <operator> <operand> {level}taglist:record-prefix[field]

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

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

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

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

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

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"

313. Other options

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

315. Varnishtop

316. Same syntax as varnishlog. Output is incremental

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

318. Common Varnishlog scenarios

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

320. Request not cacheable

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

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

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

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

325. Response not cacheable

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

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

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

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

330. None