Mysterious no content result, from an URL with pass action
Jakob Bohm
jb-varnish at wisemo.com
Tue Jun 6 12:05:25 UTC 2023
Hi all,
Just a quick update,
After changing the hitch to varnish connection from AF_UNIX to TCP,
rerunning the experiment with tcpdump active revealed that varnish
7.2.1 seemed to silently ignore HTTP/2 requests whenever my browser
chose that over HTTP/1.x . Turning off HTTP/2 in hitch seems to
make things work.
I'm still surprised that varnishd drops HTTP/2 over proxyv2 silently
with no logging that a connection was dropped, and in such a way that
web browsers interpret it as an empty page. Feels very similar to
my earlier issue that failure to bind to a specified listen address
was not shown to the sysadmin starting varnishd .
Now it's time to upgrade to 7.3.0 and improve the configuration.
On 2023-05-10 10:43, Jakob Bohm wrote:
> 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