Uploaded image for project: 'eZ Platform Enterprise Edition'
  1. eZ Platform Enterprise Edition
  2. EZEE-1693

ESI for language_switcher ( and others ) is not cachable by varnish

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Backlog
    • Priority: High
    • Resolution: Unresolved
    • Affects Version/s: 1.10.1, 1.13.0
    • Fix Version/s: None
    • Labels:
      None
    • Environment:

      varnish4, nginx, php-fpm

      Description

      There are a few ESI calls which are not cachable for varnish.

      Doing this call twice :

      curl -sD - -o /dev/null --cookie "eZSESSID98defd6ee70dfb1dea416cecdf391f58=c65an2in8ptqhig6osp4l3ecbb" http://localhost:8081
      curl -sD - -o /dev/null --cookie "eZSESSID98defd6ee70dfb1dea416cecdf391f58=c65an2in8ptqhig6osp4l3ecbb" http://localhost:8081
      

      The nginx logs for the second request reveals that calls are not cached

      172.24.0.5 - - [27/Jul/2017:13:46:55 +0000] "GET /_fragment?_path=template%3DeZStudioDemoBundle%253Aparts%253Alanguage_switcher.html.twig%26serialized_siteaccess%3DO%253A38%253A%2522eZ%255CPublish%255CCore%255CMVC%255CSymfony%255CSiteAccess%2522%253A3%253A%257Bs%253A4%253A%2522name%2522%253Bs%253A4%253A%2522site%2522%253Bs%253A12%253A%2522matchingType%2522%253Bs%253A7%253A%2522default%2522%253Bs%253A7%253A%2522matcher%2522%253BN%253B%257D%26_format%3Dhtml%26_locale%3Den_GB%26_controller%3Dezstudiodemo.controller.language_switcher%253Ashow&_hash=4zqoFT2J0v9NpKpNDvZ6ch%2FjhPjBqwaDLUf7co8uqzA%3D HTTP/1.1" 200 2734 "-" "curl/7.47.0" "172.24.0.1, 172.24.0.1"
      172.24.0.5 - - [27/Jul/2017:13:46:55 +0000] "GET /_fragment?_path=contentId%3D63%26blockId%3Db-5d5a0808-bd49-0e85-650c-c915e73b51cd%26versionNo%3D1%26serialized_siteaccess%3DO%253A38%253A%2522eZ%255CPublish%255CCore%255CMVC%255CSymfony%255CSiteAccess%2522%253A3%253A%257Bs%253A4%253A%2522name%2522%253Bs%253A4%253A%2522site%2522%253Bs%253A12%253A%2522matchingType%2522%253Bs%253A7%253A%2522default%2522%253Bs%253A7%253A%2522matcher%2522%253BN%253B%257D%26_format%3Dhtml%26_locale%3Den_GB%26_controller%3Dez_block%253ArenderBlockAction&_hash=96CMO7fH7rzRuDxt1%2Fz%2FKRBwHd9cv3z8c%2BiQ2y6H4V8%3D HTTP/1.1" 200 679 "-" "curl/7.47.0" "172.24.0.1, 172.24.0.1"
      172.24.0.5 - - [27/Jul/2017:13:46:55 +0000] "GET /_fragment?_path=contentId%3D63%26blockId%3Db-83fc6e49-d87f-9387-e4e1-b0951a3d9055%26versionNo%3D1%26serialized_siteaccess%3DO%253A38%253A%2522eZ%255CPublish%255CCore%255CMVC%255CSymfony%255CSiteAccess%2522%253A3%253A%257Bs%253A4%253A%2522name%2522%253Bs%253A4%253A%2522site%2522%253Bs%253A12%253A%2522matchingType%2522%253Bs%253A7%253A%2522default%2522%253Bs%253A7%253A%2522matcher%2522%253BN%253B%257D%26_format%3Dhtml%26_locale%3Den_GB%26_controller%3Dez_block%253ArenderBlockAction&_hash=ZVB%2Bx8GCrY609iu9fv0GD5VXCXQT6llbGFN5BNiYYAo%3D HTTP/1.1" 200 10361 "-" "curl/7.47.0" "172.24.0.1, 172.24.0.1"
      172.24.0.5 - - [27/Jul/2017:13:46:55 +0000] "GET /_fragment?_path=contentId%3D63%26blockId%3Db-294fbffd-744a-6ac6-3f29-9783799c10f6%26versionNo%3D1%26serialized_siteaccess%3DO%253A38%253A%2522eZ%255CPublish%255CCore%255CMVC%255CSymfony%255CSiteAccess%2522%253A3%253A%257Bs%253A4%253A%2522name%2522%253Bs%253A4%253A%2522site%2522%253Bs%253A12%253A%2522matchingType%2522%253Bs%253A7%253A%2522default%2522%253Bs%253A7%253A%2522matcher%2522%253BN%253B%257D%26_format%3Dhtml%26_locale%3Den_GB%26_controller%3Dez_block%253ArenderBlockAction&_hash=aWxTFx1WpEbsLHRVaRdyNdoYthpk7imhQQ6IfE1SF3Q%3D HTTP/1.1" 200 533 "-" "curl/7.47.0" "172.24.0.1, 172.24.0.1"
      172.24.0.5 - - [27/Jul/2017:13:46:55 +0000] "GET /_fragment?_path=contentId%3D63%26blockId%3Db-96ba244b-c72d-740d-0ccd-fdcec4e23af4%26versionNo%3D1%26serialized_siteaccess%3DO%253A38%253A%2522eZ%255CPublish%255CCore%255CMVC%255CSymfony%255CSiteAccess%2522%253A3%253A%257Bs%253A4%253A%2522name%2522%253Bs%253A4%253A%2522site%2522%253Bs%253A12%253A%2522matchingType%2522%253Bs%253A7%253A%2522default%2522%253Bs%253A7%253A%2522matcher%2522%253BN%253B%257D%26_format%3Dhtml%26_locale%3Den_GB%26_controller%3Dez_block%253ArenderBlockAction&_hash=GUqqvirS3UB3IdCohGbgTX5XSGnQFvH%2B5RcVx252Qug%3D HTTP/1.1" 200 465 "-" "curl/7.47.0" "172.24.0.1, 172.24.0.1"
      172.24.0.5 - - [27/Jul/2017:13:46:55 +0000] "GET /_fragment?_path=contentId%3D63%26blockId%3Db-b27742d1-628f-0c8c-a48b-0b1dd0d7e5f9%26versionNo%3D1%26serialized_siteaccess%3DO%253A38%253A%2522eZ%255CPublish%255CCore%255CMVC%255CSymfony%255CSiteAccess%2522%253A3%253A%257Bs%253A4%253A%2522name%2522%253Bs%253A4%253A%2522site%2522%253Bs%253A12%253A%2522matchingType%2522%253Bs%253A7%253A%2522default%2522%253Bs%253A7%253A%2522matcher%2522%253BN%253B%257D%26_format%3Dhtml%26_locale%3Den_GB%26_controller%3Dez_block%253ArenderBlockAction&_hash=fi7AJ5GXnLbL8maD37elGqnC8sSS23cPNyl7Ij4ZDn0%3D HTTP/1.1" 200 3656 "-" "curl/7.47.0" "172.24.0.1, 172.24.0.1"
      172.24.0.5 - - [27/Jul/2017:13:46:55 +0000] "GET /_fragment?_path=contentId%3D63%26blockId%3Db-bf850b3f-e770-6e8f-46d0-ceff8d0c94f4%26versionNo%3D1%26serialized_siteaccess%3DO%253A38%253A%2522eZ%255CPublish%255CCore%255CMVC%255CSymfony%255CSiteAccess%2522%253A3%253A%257Bs%253A4%253A%2522name%2522%253Bs%253A4%253A%2522site%2522%253Bs%253A12%253A%2522matchingType%2522%253Bs%253A7%253A%2522default%2522%253Bs%253A7%253A%2522matcher%2522%253BN%253B%257D%26_format%3Dhtml%26_locale%3Den_GB%26_controller%3Dez_block%253ArenderBlockAction&_hash=4965Dd6FS5jIkQmhT9gFop7zx227fBgUshg9oTVRfLw%3D HTTP/1.1" 200 467 "-" "curl/7.47.0" "172.24.0.1, 172.24.0.1"
      172.24.0.5 - - [27/Jul/2017:13:46:55 +0000] "GET /_fragment?_path=contentId%3D63%26blockId%3Db-b3a66965-cec8-8c27-bb5c-a773e26bad3a%26versionNo%3D1%26serialized_siteaccess%3DO%253A38%253A%2522eZ%255CPublish%255CCore%255CMVC%255CSymfony%255CSiteAccess%2522%253A3%253A%257Bs%253A4%253A%2522name%2522%253Bs%253A4%253A%2522site%2522%253Bs%253A12%253A%2522matchingType%2522%253Bs%253A7%253A%2522default%2522%253Bs%253A7%253A%2522matcher%2522%253BN%253B%257D%26_format%3Dhtml%26_locale%3Den_GB%26_controller%3Dez_block%253ArenderBlockAction&_hash=TeHZlJC%2BDt1JICT%2BFgZw3ce%2B1JvFyfCsbJIELV7umU4%3D HTTP/1.1" 200 3656 "-" "curl/7.47.0" "172.24.0.1, 172.24.0.1"
      
      

      varnishlog reveals that in the first request ("GET /_fragment?_path=template%3DeZStudioDemoBundle%253Aparts%253Alanguage_switcher.html.twig(...)") the back-end responds with "Cache-Control: no-cache"

      # varnishlog -g request
      (...)
      *** << BeReq    >> 32874     
      --- Begin          bereq 32873 fetch
      --- Timestamp      Start: 1501163214.896289 0.000000 0.000000
      --- BereqMethod    GET
      --- BereqURL       /_fragment?_path=template%3DeZStudioDemoBundle%253Aparts%253Alanguage_switcher.html.twig%26serialized_siteaccess%3DO%253A38%253A%2522eZ%255CPublish%255CCore%255CMVC%255CSymfony%255CSiteAccess%2522%253A3%253A%257Bs%253A4%253A%2522name%2522%253Bs%253A4%253
      --- BereqProtocol  HTTP/1.1
      --- BereqHeader    Host: localhost:8081
      --- BereqHeader    User-Agent: curl/7.47.0
      --- BereqHeader    x-user-hash: b1731d46b0e7a375a5b024e950fdb8d49dd25af85a5c7dd5116ad2a18cda82cb
      --- BereqHeader    Surrogate-Capability: abc=ESI/1.0
      --- BereqHeader    X-Forwarded-For: 172.24.0.1, 172.24.0.1
      --- BereqHeader    accept: */*
      --- BereqHeader    cookie: eZSESSID98defd6ee70dfb1dea416cecdf391f58=c65an2in8ptqhig6osp4l3ecbb
      --- BereqHeader    Accept-Encoding: gzip
      --- BereqHeader    X-Varnish: 32874
      --- VCL_call       BACKEND_FETCH
      --- VCL_return     fetch
      --- BackendOpen    24 boot.ezplatform 172.24.0.4 80 172.24.0.5 55364
      --- BackendStart   172.24.0.4 80
      --- Timestamp      Bereq: 1501163214.896468 0.000179 0.000179
      --- Timestamp      Beresp: 1501163215.000596 0.104307 0.104128
      --- BerespProtocol HTTP/1.1
      --- BerespStatus   200
      --- BerespReason   OK
      --- BerespHeader   Server: nginx/1.8.1
      --- BerespHeader   Content-Type: text/html; charset=UTF-8
      --- BerespHeader   Transfer-Encoding: chunked
      --- BerespHeader   Connection: keep-alive
      --- BerespHeader   X-Powered-By: PHP/7.1.2
      --- BerespHeader   Cache-Control: no-cache
      --- BerespHeader   Date: Thu, 27 Jul 2017 13:46:54 GMT
      --- BerespHeader   X-Cache-Debug: 1
      --- BerespHeader   Vary: X-User-Hash
      --- BerespHeader   X-Debug-Token: 750359
      --- BerespHeader   X-Debug-Token-Link: http://localhost:8081/_profiler/750359
      --- TTL            RFC 120 10 0 1501163215 1501163215 1501163214 0 0
      --- VCL_call       BACKEND_RESPONSE
      --- TTL            VCL 120 3600 0 1501163215
      --- TTL            VCL 120 3600 0 1501163215
      --- VCL_return     deliver
      --- Storage        malloc Transient
      --- ObjProtocol    HTTP/1.1
      --- ObjStatus      200
      --- ObjReason      OK
      --- ObjHeader      Server: nginx/1.8.1
      --- ObjHeader      Content-Type: text/html; charset=UTF-8
      --- ObjHeader      X-Powered-By: PHP/7.1.2
      --- ObjHeader      Cache-Control: no-cache
      --- ObjHeader      Date: Thu, 27 Jul 2017 13:46:54 GMT
      --- ObjHeader      X-Cache-Debug: 1
      --- ObjHeader      Vary: X-User-Hash
      --- ObjHeader      X-Debug-Token: 750359
      --- ObjHeader      X-Debug-Token-Link: http://localhost:8081/_profiler/750359
      --- Fetch_Body     2 chunked stream
      --- BackendReuse   24 boot.ezplatform
      --- Timestamp      BerespBody: 1501163215.000823 0.104534 0.000226
      --- Length         2722
      --- BereqAcct      900 0 900 339 2722 3061
      --- End
      (...)
      

      I assume it should return a s-maxage instead?

      The same goes for other ESI (which is called multiple times) I guess

      System setup using :

      export COMPOSE_FILE=doc/docker-compose/base-dev.yml
      docker-compose -f doc/docker-compose/install.yml up --abort-on-container-exit
      # Next, change X-User-Hash from '38015b703d82206ebc01d17a39c727e5' to 'b1731d46b0e7a375a5b024e950fdb8d49dd25af85a5c7dd5116ad2a18cda82cb' in doc/varnish/vcl/varnish4.vcl
      docker-compose -f doc/docker-compose/base-dev.yml -f doc/docker-compose/varnish.yml up -d --force-recreate
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              Unassigned
              Reporter:
              vidar.langseid@ez.no Vidar Langseid
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

                Dates

                Created:
                Updated: