Mysterious no content result, from an URL with pass action

Jakob Bohm jb-varnish at wisemo.com
Wed May 10 08:43:24 UTC 2023


On 2023-05-10 06:49, Guillaume Quintard wrote:
> Hi Jakob,
> 
> (Sorry i didn't see that email sooner, it was in my spam folder)
> 
> Looking at the log, I'm not sure what varnish should be loud about :-)
> 204 is a success code, and more importantly it's generated by the 
> backend, so varnish is happily passing it along.
> 
> At the http level, everything looks about right, but I can guess from 
> your apparent irritation that something wrong one level up, let's try to 
> debug that.
> 
> What kind of response are you expecting, if not a 204? And maybe, what 
> is that endpoint supposed to do? Given that the method was GET, and that 
> there's no body, my only guess is that there's something happening with 
> the TeamCity-AgentSessionId header, maybe?
> Is the 27 seconds processing time expected?
> 

Expecting uncachable results that vary with time and are only sometimes 
204, and the response time is also somewhat unexpected, but is not 
clearly logged (only a Varnish expert like you can decrypt that it is 27 
seconds).  It is also unclear if Varnish is always receiving those 
responses from the backend.

I also expected some other URLs in the log, but don't see them.

Maybe I should find another day to run the experiments again.

> Cheers,
> 
> On Tue, May 9, 2023, 15:12 Jakob Bohm <jb-varnish at wisemo.com 
> <mailto:jb-varnish at wisemo.com>> wrote:
> 
>     Dear Varnish mailing list,
> 
>     When testing varnish as a reverse proxy for multiple services
>     including a local JetBrains TeamCity instance, requests to that
>     teamcity server get corrupted into "204 No Content" replies.
> 
>     Once again, Varnish fails to say why it is refusing to do its job.
>     Any sane program should explicitly and loudly report any fatal error
>     that stops it working.  Loudly means the sysadmin or other user
>     invoking the program receives the exaxt error message by default
>     instead of something highly indirect, hidden behind a debug option
>     or otherwisse highly non-obvious.
> 
>     Here's a relevant clip from the VCL:
> 
>     # Various top comments
>     vcl 4.1;
> 
>     import std;
>     import proxy;
> 
>     # Backend sending requests to the teamcity main server
>     backend teamcity {
>           .host = "2a01:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx";
>           .port = "8111";
>     }
> 
>     # IP ranges allowed to access the build server and staging server
>     acl buildtrust {
>           "127.0.0.0"/8;
>           "::"/128;
>           "various others"/??;
>     }
> 
>     # IP ranges allowed to attempt login to things that use our common login
>     #    database
>     acl logintrust {
>           "various others"/??;
>     }
> 
>     sub vcl_recv {
>           # Happens before we check if we have this in cache already.
>           #
>           # Typically you clean up the request here, removing cookies you
>     don't need,
>           # rewriting the request, etc.
>           if (proxy.is_ssl()) {
>               set req.http.Scheme = "https";
>               set req.http.ssl-version = proxy.ssl_version();
>               set req.http.X-Forwarded-Proto = "https";
>               set req.http.X-SSL-cipher = proxy.ssl_cipher();
>               std.log("TLS-SSL-VERSION: " + proxy.ssl_version());
>           } else {
>               set req.http.X-Forwarded-Proto = req.http.Scheme;
>               unset req.http.ssl-version;
>               unset req.http.X-SSL-cipher;
>               std.log("TLS-SSL-VERSION: none");
>           }
>           unset req.http.X-SSL-Subject;
>           unset req.http.X-SSL-Issuer;
>           unset req.http.X-SSL-notBefore;
>           unset req.http.X-SSL-notAfter;
>           unset req.http.X-SSL-serial;
>           unset req.http.X-SSL-certificate;
> 
>           set req.http.X-Forwarded-For = client.ip;
> 
>           call vcl_req_host;
> 
>           if (req.url ~ "^/something") {
>               set req.backend_hint = be1;
>           } else if (req.url !~ "^/somethingelse" &&
>                      !(client.ip ~ logintrust) &&
>                      !(client.ip ~ buildtrust)) {
>               # Treat as unknown by redirecting to public website
>               if ((req.url ~ "^/yeatanother") ||
>                   (req.url ~ "^/yetsomeother")) {
>                   return (synth(752));
>               } else if (req.url ~ "^/yetsomethird") {
>                   return (synth(753));
>               }
>               return (synth(751));
>           } else if (req.http.Scheme && req.http.Scheme != "https") {
>               # See example at
>     https://www.varnish-software.com/developers/tutorials/redirect/
>               return (synth(750));
>           } else if (req.url ~ "^/somethingelse") {
>               set req.backend_hint = be1;
>           } else if (req.url ~ "^/somethingfourth") {
>               set req.backend_hint = be2;
>           } else if (req.url ~ "^/somethingfifth") {
>               set req.backend_hint = be2;
>           } else if (!(client.ip ~ buildtrust)) {
>               # Treat as unknown by redirecting to public website
>               if ((req.url ~ "^/yeatanother") ||
>                   (req.url ~ "^/yetsomeother")) {
>                   return (synth(752));
>               } else if (req.url ~ "^/yetsomethird") {
>                   return (synth(753));
>               }
>               return (synth(751));
>           } else if (req.url ~ "^/teamcity") {
>               set req.backend_hint= teamcity;
>               return (pass);
>     #    } else if (req.http.host ~ "^somethingsixths") {
>     #       set req.backend_hint= be4;
>           } else {
>               set req.backend_hint = be5;
>           }
>           call vcl_req_method;
>           call vcl_req_authorization;
>           call vcl_req_cookie;
>           return (hash);
>     }
> 
>     sub vcl_backend_response {
>           # Happens after we have read the response headers from the
>     backend.
>           #
>           # Here you clean the response headers, removing silly Set-Cookie
>     headers
>           # and other mistakes your backend does.
> 
>           # The Java webserver in teamcity is incompatible with varnish
>     connection
>           #    pooling
>           if (beresp.backend == teamcity) {
>               if (beresp.http.Connection &&
>                   beresp.http.Connection !~ "keep-alive") {
>                   set beresp.http.Connection += ", close";
>               } else {
>                   set beresp.http.Connection = "close";
>               }
>           }
>     }
> 
>     +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
>     First 43 lines of varnishlog -v 2>&1
> 
>     *              << BeReq    >>   9
>     -            9 Begin          b bereq 8 pass
>     -            9 VCL_use        b boot
>     -            9 Timestamp      b Start: 1681484803.177212 0.000000
>     0.000000
>     -            9 BereqMethod    b GET
>     -            9 BereqURL       b /teamcity/app/agents/v1/commands/next
>     -            9 BereqProtocol  b HTTP/1.1
>     -            9 BereqHeader    b TeamCity-AgentSessionId:
>     L6juFAAt1awJDt6UKToPIxQq7wpBF89C
>     -            9 BereqHeader    b User-Agent: TeamCity Agent 2021.2.3
>     -            9 BereqHeader    b Host: vmachine.example.com
>     <http://vmachine.example.com>
>     -            9 BereqHeader    b Via: 1.1 vmachine (Varnish/7.2)
>     -            9 BereqHeader    b Scheme: https
>     -            9 BereqHeader    b ssl-version: TLSv1.3
>     -            9 BereqHeader    b X-Forwarded-Proto: https
>     -            9 BereqHeader    b X-SSL-cipher: TLS_AES_256_GCM_SHA384
>     -            9 BereqHeader    b X-Forwarded-For: 192.168.2.112
>     -            9 BereqHeader    b X-Varnish: 9
>     -            9 VCL_call       b BACKEND_FETCH
>     -            9 VCL_return     b fetch
>     -            9 Timestamp      b Fetch: 1681484803.177227 0.000014
>     0.000014
>     -            9 Timestamp      b Connected: 1681484803.177603 0.000390
>     0.000375
>     -            9 BackendOpen    b 24 teamcity
>     2a01:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx:xxxx 8111 2a01:yyyy:yyyy:yyyy::yyyy
>     59548 connect
>     -            9 Timestamp      b Bereq: 1681484803.177645 0.000432
>     0.000042
>     -            9 BerespReason   b No Content
>     -            9 Timestamp      b Beresp: 1681484830.672487 27.495274
>     27.494842
>     -            9 BerespProtocol b HTTP/1.1
>     -            9 BerespStatus   b 204
>     -            9 BerespReason   b No Content
>     -            9 BerespHeader   b TeamCity-Node-Id: MAIN_SERVER
>     -            9 BerespHeader   b Date: Fri, 14 Apr 2023 15:07:10 GMT
>     -            9 VCL_call       b BACKEND_RESPONSE
>     -            9 BerespHeader   b Connection: close
>     -            9 VCL_return     b deliver
>     -            9 Timestamp      b Process: 1681484830.672563 27.495350
>     0.000075
>     -            9 Filters        b
>     -            9 Storage        b malloc Transient
>     -            9 Fetch_Body     b 0 none -
>     -            9 BackendClose   b 24 teamcity close Backend/VCL requested
>     close
>     -            9 Timestamp      b BerespBody: 1681484830.672926 27.495713
>     0.000362
>     -            9 Length         b 0
>     -            9 BereqAcct      b 345 0 345 85 0 85
>     -            9 End            b
> 



Enjoy

Jakob
-- 
Jakob Bohm, CIO, Partner, WiseMo A/S.  https://www.wisemo.com
Transformervej 29, 2860 Søborg, Denmark.  Direct +45 31 13 16 10
This public discussion message is non-binding and may contain errors.
WiseMo - Remote Service Management for PCs, Phones and Embedded


More information about the varnish-misc mailing list