[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#960304: snapshot.debian.org: Snapshot repo repeatedly cutting off connection, returning partial content



Hi,

I just had a look at this again.  It seems the issue comes from our
varnish setup, as things are fine when hitting apache directly.  But the
combination of streaming and a mix of small and large files in varnish's
cache leads to things like the below, where varnish gives up after
hitting nuke_limit (50) files to make space in the cache.

Cheers,
Julien

> jcristau@sallinen:~$ sudo varnishlog -g session -q 'ReqUrl eq "/file/51288439bde385157c889f23483b467608586aad"'
> *   << Session  >> 3937381   
> -   Begin          sess 0 HTTP/1
> -   SessOpen       2a01:cb08:88c7:5b00:6798:1a76:ef57:4714 58440 a1 2001:630:206:4000:1a1a:0:c13e:ca1b 80 1628066418.824244 26
> -   Link           req 3937382 rxreq
> -   SessClose      REM_CLOSE 2.846
> -   End            
> **  << Request  >> 3937382   
> --  Begin          req 3937381 rxreq
> --  Timestamp      Start: 1628066418.824321 0.000000 0.000000
> --  Timestamp      Req: 1628066418.824321 0.000000 0.000000
> --  ReqStart       2a01:cb08:88c7:5b00:6798:1a76:ef57:4714 58440 a1
> --  ReqMethod      GET
> --  ReqURL         /file/51288439bde385157c889f23483b467608586aad
> --  ReqProtocol    HTTP/1.1
> --  ReqHeader      Host: snapshot.debian.org
> --  ReqHeader      User-Agent: curl/7.74.0
> --  ReqHeader      Accept: */*
> --  ReqHeader      X-Forwarded-For: 2a01:cb08:88c7:5b00:6798:1a76:ef57:4714
> --  VCL_call       RECV
> --  VCL_return     hash
> --  VCL_call       HASH
> --  VCL_return     lookup
> --  VCL_call       MISS
> --  VCL_return     fetch
> --  Link           bereq 3937383 fetch
> --  Timestamp      Fetch: 1628066418.826448 0.002127 0.002127
> --  RespProtocol   HTTP/1.1
> --  RespStatus     200
> --  RespReason     OK
> --  RespHeader     Date: Wed, 04 Aug 2021 08:40:18 GMT
> --  RespHeader     Server: Apache
> --  RespHeader     X-Content-Type-Options: nosniff
> --  RespHeader     X-Frame-Options: sameorigin
> --  RespHeader     Referrer-Policy: no-referrer
> --  RespHeader     X-Xss-Protection: 1
> --  RespHeader     Permissions-Policy: interest-cohort=()
> --  RespHeader     Last-Modified: Fri, 20 Apr 2018 20:58:57 GMT
> --  RespHeader     ETag: "2c0cb0ca-56a4df4e5684a"
> --  RespHeader     Content-Length: 739029194
> --  RespHeader     X-Clacks-Overhead: GNU Terry Pratchett
> --  RespHeader     Cache-Control: max-age=31536000, public
> --  RespHeader     X-Varnish: 3937382
> --  RespHeader     Age: 0
> --  RespHeader     Via: 1.1 varnish (Varnish/6.1)
> --  VCL_call       DELIVER
> --  RespHeader     connection: close
> --  VCL_return     deliver
> --  Timestamp      Process: 1628066418.826480 0.002160 0.000032
> --  RespHeader     Accept-Ranges: bytes
> --  Timestamp      Resp: 1628066421.667356 2.843036 2.840876
> --  ReqAcct        128 0 128 512 19857408 19857920
> --  End            
> *** << BeReq    >> 3937383   
> --- Begin          bereq 3937382 fetch
> --- Timestamp      Start: 1628066418.824419 0.000000 0.000000
> --- BereqMethod    GET
> --- BereqURL       /file/51288439bde385157c889f23483b467608586aad
> --- BereqProtocol  HTTP/1.1
> --- BereqHeader    Host: snapshot.debian.org
> --- BereqHeader    User-Agent: curl/7.74.0
> --- BereqHeader    Accept: */*
> --- BereqHeader    X-Forwarded-For: 2a01:cb08:88c7:5b00:6798:1a76:ef57:4714
> --- BereqHeader    Accept-Encoding: gzip
> --- BereqHeader    X-Varnish: 3937383
> --- VCL_call       BACKEND_FETCH
> --- VCL_return     fetch
> --- BackendOpen    32 default 127.0.0.1 80 127.0.0.1 56612
> --- BackendStart   127.0.0.1 80
> --- Timestamp      Bereq: 1628066418.824718 0.000299 0.000299
> --- Timestamp      Beresp: 1628066418.826314 0.001895 0.001596
> --- BerespProtocol HTTP/1.1
> --- BerespStatus   200
> --- BerespReason   OK
> --- BerespHeader   Date: Wed, 04 Aug 2021 08:40:18 GMT
> --- BerespHeader   Server: Apache
> --- BerespHeader   X-Content-Type-Options: nosniff
> --- BerespHeader   X-Frame-Options: sameorigin
> --- BerespHeader   Referrer-Policy: no-referrer
> --- BerespHeader   X-Xss-Protection: 1
> --- BerespHeader   Permissions-Policy: interest-cohort=()
> --- BerespHeader   Upgrade: h2,h2c
> --- BerespHeader   Connection: Upgrade
> --- BerespHeader   Last-Modified: Fri, 20 Apr 2018 20:58:57 GMT
> --- BerespHeader   ETag: "2c0cb0ca-56a4df4e5684a"
> --- BerespHeader   Accept-Ranges: bytes
> --- BerespHeader   Content-Length: 739029194
> --- BerespHeader   X-Clacks-Overhead: GNU Terry Pratchett
> --- BerespHeader   Cache-Control: max-age=31536000, public
> --- TTL            RFC 31536000 10 0 1628066419 1628066419 1628066418 0 31536000 cacheable
> --- VCL_call       BACKEND_RESPONSE
> --- VCL_return     deliver
> --- Filters        
> --- Storage        file s0
> --- Fetch_Body     3 length stream
> --- ExpKill        LRU_Cand p=0x7fa236c79b00 f=0x0 r=1
> --- ExpKill        LRU x=3873725
> --- ExpKill        LRU_Cand p=0x7fa236c6f700 f=0x0 r=1
> --- ExpKill        LRU x=3696172
> --- ExpKill        LRU_Cand p=0x7fa238320d40 f=0x0 r=1
> --- ExpKill        LRU x=3873726
> --- ExpKill        LRU_Cand p=0x7fa23e73c640 f=0x0 r=1
> --- ExpKill        LRU x=3627041
> --- ExpKill        LRU_Cand p=0x7fa2388080c0 f=0x0 r=1
> --- ExpKill        LRU x=3696176
> --- ExpKill        LRU_Cand p=0x7fa236864680 f=0x0 r=1
> --- ExpKill        LRU x=3902662
> --- ExpKill        LRU_Cand p=0x7fa2402ca500 f=0x0 r=1
> --- ExpKill        LRU x=3696177
> --- ExpKill        LRU_Cand p=0x7fa238807dc0 f=0x0 r=1
> --- ExpKill        LRU x=3696178
> --- ExpKill        LRU_Cand p=0x7fa23eee1080 f=0x0 r=1
> --- ExpKill        LRU x=3902663
> --- ExpKill        LRU_Cand p=0x7fa23e73c580 f=0x0 r=1
> --- ExpKill        LRU x=3627042
> --- ExpKill        LRU_Cand p=0x7fa236c7a280 f=0x0 r=1
> --- ExpKill        LRU x=3627043
> --- ExpKill        LRU_Cand p=0x7fa23fa9a440 f=0x0 r=1
> --- ExpKill        LRU x=3696185
> --- ExpKill        LRU_Cand p=0x7fa236463200 f=0x0 r=1
> --- ExpKill        LRU x=3873739
> --- ExpKill        LRU_Cand p=0x7fa23faf6840 f=0x0 r=1
> --- ExpKill        LRU x=3627044
> --- ExpKill        LRU_Cand p=0x7fa23ca36780 f=0x0 r=1
> --- ExpKill        LRU x=3873740
> --- ExpKill        LRU_Cand p=0x7fa23ceb0f80 f=0x0 r=1
> --- ExpKill        LRU x=3784856
> --- ExpKill        LRU_Cand p=0x7fa2361702c0 f=0x0 r=1
> --- ExpKill        LRU x=3457616
> --- ExpKill        LRU_Cand p=0x7fa237402700 f=0x0 r=1
> --- ExpKill        LRU x=3784857
> --- ExpKill        LRU_Cand p=0x7fa23fe35a40 f=0x0 r=1
> --- ExpKill        LRU x=3901352
> --- ExpKill        LRU_Cand p=0x7fa236d032c0 f=0x0 r=1
> --- ExpKill        LRU x=3624875
> --- ExpKill        LRU_Cand p=0x7fa23689e2c0 f=0x0 r=1
> --- ExpKill        LRU x=3696197
> --- ExpKill        LRU_Cand p=0x7fa238808300 f=0x0 r=1
> --- ExpKill        LRU x=3873741
> --- ExpKill        LRU_Cand p=0x7fa23e746c00 f=0x0 r=1
> --- ExpKill        LRU x=3696198
> --- ExpKill        LRU_Cand p=0x7fa2364d7900 f=0x0 r=1
> --- ExpKill        LRU x=3696199
> --- ExpKill        LRU_Cand p=0x7fa236c777c0 f=0x0 r=1
> --- ExpKill        LRU x=3873742
> --- ExpKill        LRU_Cand p=0x7fa23fa99b40 f=0x0 r=1
> --- ExpKill        LRU x=3696200
> --- ExpKill        LRU_Cand p=0x7fa236c86880 f=0x0 r=1
> --- ExpKill        LRU x=3873743
> --- ExpKill        LRU_Cand p=0x7fa2368a30c0 f=0x0 r=1
> --- ExpKill        LRU x=3696201
> --- ExpKill        LRU_Cand p=0x7fa23fa9aa40 f=0x0 r=1
> --- ExpKill        LRU x=3460107
> --- ExpKill        LRU_Cand p=0x7fa23610b040 f=0x0 r=1
> --- ExpKill        LRU x=3460108
> --- ExpKill        LRU_Cand p=0x7fa23cea5f40 f=0x0 r=1
> --- ExpKill        LRU x=3724090
> --- ExpKill        LRU_Cand p=0x7fa23da433c0 f=0x0 r=1
> --- ExpKill        LRU x=3724091
> --- ExpKill        LRU_Cand p=0x7fa23611f140 f=0x0 r=1
> --- ExpKill        LRU x=3627063
> --- ExpKill        LRU_Cand p=0x7fa23ceac000 f=0x0 r=1
> --- ExpKill        LRU x=3724092
> --- ExpKill        LRU_Cand p=0x7fa23616f900 f=0x0 r=1
> --- ExpKill        LRU x=3720845
> --- ExpKill        LRU_Cand p=0x7fa236c6ef80 f=0x0 r=1
> --- ExpKill        LRU x=2487312
> --- ExpKill        LRU_Cand p=0x7fa238809bc0 f=0x0 r=1
> --- ExpKill        LRU x=3627066
> --- ExpKill        LRU_Cand p=0x7fa238320e00 f=0x0 r=1
> --- ExpKill        LRU x=3724093
> --- ExpKill        LRU_Cand p=0x7fa2364d8800 f=0x0 r=1
> --- ExpKill        LRU x=3902697
> --- ExpKill        LRU_Cand p=0x7fa24022cc00 f=0x0 r=1
> --- ExpKill        LRU x=3460117
> --- ExpKill        LRU_Cand p=0x7fa23fa999c0 f=0x0 r=1
> --- ExpKill        LRU x=3460118
> --- ExpKill        LRU_Cand p=0x7fa238320140 f=0x0 r=1
> --- ExpKill        LRU x=3724098
> --- ExpKill        LRU_Cand p=0x7fa236cd6340 f=0x0 r=1
> --- ExpKill        LRU x=3627069
> --- ExpKill        LRU_Cand p=0x7fa236109180 f=0x0 r=1
> --- ExpKill        LRU x=3724099
> --- ExpKill        LRU_Cand p=0x7fa23ceac0c0 f=0x0 r=1
> --- ExpKill        LRU x=3724100
> --- ExpKill        LRU_Cand p=0x7fa23ce69c80 f=0x0 r=1
> --- ExpKill        LRU x=3460122
> --- ExpKill        LRU_Cand p=0x7fa238320200 f=0x0 r=1
> --- ExpKill        LRU x=3724101
> --- ExpKill        LRU_Cand p=0x7fa23f205540 f=0x0 r=1
> --- ExpKill        LRU x=3724102
> --- ExpKill        LRU_Cand p=0x7fa23611f080 f=0x0 r=1
> --- ExpKill        LRU x=3627070
> --- ExpKill        LRU_Cand p=0x7fa236128880 f=0x0 r=1
> --- ExpKill        LRU x=3724103
> --- ExpKill        LRU reached nuke_limit
> --- FetchError     Could not get storage
> --- BackendClose   32 default
> --- BereqAcct      229 0 229 471 106479616 106480087
> --- End            


Reply to: