Kristian,<br><br>Here is the VCL and varnishstats requested. Unfortunatelly the varnishlog runs so fast so I can't catch the HIT/MISS logs just for one request.<br><br># VCL<br><br>backend be1 {<br>    .host = "X.X.X.X";<br>
}<br><br>acl purge {<br>    "localhost";<br>}<br><br>sub vcl_recv {<br>    set req.grace = 60s;<br>    if (req.http.host == "<a href="http://domain.com">domain.com</a>") {<br>        set req.backend = be1;<br>
    }<br>    if (req.request == "PURGE") {<br>        if (!client.ip ~ purge) {<br>            error 405 "Not allowed.";<br>        }<br>        return (lookup);<br>    }<br>    if (req.http.x-forwarded-for) {<br>
        set req.http.X-Forwarded-For = req.http.X-Forwarded-For ", " client.ip;<br>    }<br>    else {<br>        set req.http.X-Forwarded-For = client.ip;<br>    }<br>    if (req.request != "GET" && req.request != "HEAD" && req.request != "PUT" && req.request != "POST" && req.request != "TRACE" && req.request != "OPTIONS" && req.request != "DELETE") {<br>
        return (pipe);<br>    }<br>    if (req.http.Cookie ~ "^\s*$") {<br>        unset req.http.Cookie;<br>    }<br>    if (!req.url~ "\.php\?.*$" && !req.url~ "search" ) {<br>        set req.url = regsub(req.url, "\?.*$", "");<br>
    } <br>    if (req.request != "GET" && req.request != "HEAD") {<br>        return (pass);<br>    }<br>    if (req.url ~ "^(files|misc|sites|themes|modules|sfx)/" || req.url ~ "\.(txt|TXT|ico|ICO|css|CSS|png|PNG|jpg|JPG|gif|GIF|swf|SWF|flv|FLV|mp4|MP4|mp3|MP3|js|JS|xml|XML|jpeg|JPEG)$") {<br>
        unset req.http.Cookie;<br>        remove req.http.Referer;<br>        remove req.http.User-Agent;<br>        remove req.http.Accept-Language;<br>        remove req.http.Accept-Charset;<br>        remove req.http.Accept;<br>
        remove req.http.Cache-Control;<br>    }<br>    if (req.http.Accept-Encoding) {<br>        if (req.url ~ "\.(jpg|png|gif|gz|tgz|bz2|tbz|mp3|ogg|flv|mp4)$") {<br>            remove req.http.Accept-Encoding;<br>
        }<br>        elsif (req.http.Accept-Encoding ~ "gzip") {<br>            set req.http.Accept-Encoding = "gzip";<br>        }<br>        else {<br>            remove req.http.Accept-Encoding;<br>
        }<br>        if (req.request == "GET" && req.url ~ "\.(svg|swf|ico|mp3|mp4|m4a|ogg|mov|avi|wmv)$") {<br>            return (lookup);<br>        }<br>        if (req.request == "GET" && req.url ~ "\.(png|gif|jpg|jpeg)$") {<br>
            return (lookup);<br>        }<br>    } <br>    return (lookup);<br>}<br><br>sub vcl_pipe {<br>    set bereq.http.connection = "close";<br>    return (pipe);<br>}<br><br>sub vcl_pass {<br>    return (pass);<br>
}<br><br>sub vcl_hash {<br>    if (req.http.Cookie) {<br>        set req.hash += req.http.Cookie;<br>    }<br>    set req.hash += req.url;<br>    if (req.http.host) {<br>        set req.hash += req.http.host;<br>    }<br>
    else {<br>        set req.hash += server.ip;<br>    }<br>    return (hash);<br>}<br><br>sub vcl_hit {<br>    return (deliver);<br>}<br><br>sub vcl_miss {<br>    return (fetch);<br>}<br><br>sub vcl_fetch {<br>    unset beresp.http.Etag;<br>
    if (!beresp.cacheable) {<br>        set beresp.http.X-Cacheable = "NO:Not Cacheable";<br>    }<br>    elsif(req.http.Cookie ~"(UserID|_session)") {<br>        set beresp.http.X-Cacheable = "NO:Got Session";<br>
        return (pass);<br>    }<br>    elsif ( beresp.http.Cache-Control ~ "private") {<br>        set beresp.http.X-Cacheable = "NO:Cache-Control=private";<br>        return (pass);<br>    }<br>    elsif ( beresp.ttl < 1s ) {<br>
        set beresp.ttl   = 5s;<br>        set beresp.grace = 5s;<br>        set beresp.http.X-Cacheable = "YES:FORCED";<br>    }<br>    else {<br>        set beresp.http.X-Cacheable = "YES";<br>    }<br>
    if (req.url ~ "\.(jpg|png|gif|gz|tgz|bz2|tbz|mp3|ogg|flv|swf|mp4|mp3|js|xml)$") {<br>        unset beresp.http.set-cookie;<br>    }<br>    if (beresp.http.Set-Cookie) {<br>        return (pass);<br>    }<br>
    if (beresp.status == 404 || beresp.status == 503) {<br>        set beresp.ttl = 1s;<br>    }<br>    set beresp.http.X-Cacheable = beresp.ttl;<br>    return (deliver);<br>}<br><br>sub vcl_deliver {<br>    if (obj.hits > 0) {<br>
        set resp.http.X-Varnish-Cache = "HIT Varnish (" obj.hits ")";   <br>    }<br>    else {<br>        set resp.http.X-Varnish-Cache = "MISS Varnish";<br>    }<br>    return (deliver);<br>
}<br><br>sub vcl_error {<br>    set obj.http.Content-Type = "text/html; charset=utf-8";<br>    synthetic {"<br>        <?xml version="1.0" encoding="utf-8"?><br>        <!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Strict//EN" "<a href="http://www.w3.org/TR/xhtml1/DTD/xhtml1-strict.dtd">http://www.w3.org/TR/xhtml1/DTD/xhtml1-strict.dtd</a>"><br>
        <html><br>            <head><br>                <title>"} obj.status " " obj.response {"</title><br>            </head><br>            <body><br>                <h1>Error "} obj.status " " obj.response {"</h1><br>
                <p>"} obj.response {"</p><br>                <h3>Guru Meditation:</h3><br>                <p>XID: "} req.xid {"</p><br>                <hr><br>
                <p>Varnish cache server</p><br>            </body><br>        </html><br>    "};<br>    return (deliver);<br>}<br><br>------<br><br># varnishstats -1<br><br>client_conn           9514820       148.86 Client connections accepted<br>
client_drop                 0         0.00 Connection dropped, no sess/wrk<br>client_req          102670372      1606.26 Client requests received<br>cache_hit            96847567      1515.16 Cache hits<br>cache_hitpass         5716515        89.43 Cache hits for pass<br>
cache_miss             106255         1.66 Cache misses<br>backend_conn           321210         5.03 Backend conn. success<br>backend_unhealthy            0         0.00 Backend conn. not attempted<br>backend_busy                0         0.00 Backend conn. too many<br>
backend_fail             4889         0.08 Backend conn. failures<br>backend_reuse         5496709        85.99 Backend conn. reuses<br>backend_toolate         39922         0.62 Backend conn. was closed<br>backend_recycle       5536644        86.62 Backend conn. recycles<br>
backend_unused              0         0.00 Backend conn. unused<br>fetch_head               2267         0.04 Fetch head<br>fetch_length          3542759        55.43 Fetch with Length<br>fetch_chunked            6938         0.11 Fetch chunked<br>
fetch_eof                   0         0.00 Fetch EOF<br>fetch_bad                   0         0.00 Fetch had bad headers<br>fetch_close            104849         1.64 Fetch wanted close<br>fetch_oldhttp               0         0.00 Fetch pre HTTP/1.1 closed<br>
fetch_zero            2161065        33.81 Fetch zero len<br>fetch_failed                0         0.00 Fetch failed<br>n_sess_mem               5257          .   N struct sess_mem<br>n_sess                   4645          .   N struct sess<br>
n_object               105631          .   N struct object<br>n_vampireobject             0          .   N unresurrected objects<br>n_objectcore           106147          .   N struct objectcore<br>n_objecthead            57775          .   N struct objecthead<br>
n_smf                       0          .   N struct smf<br>n_smf_frag                  0          .   N small free smf<br>n_smf_large                 0          .   N large free smf<br>n_vbe_conn                  8          .   N struct vbe_conn<br>
n_wrk                     521          .   N worker threads<br>n_wrk_create             8114         0.13 N worker threads created<br>n_wrk_failed                0         0.00 N worker threads not created<br>n_wrk_max                1323         0.02 N worker threads limited<br>
n_wrk_queue                 0         0.00 N queued work requests<br>n_wrk_overflow         232093         3.63 N overflowed work requests<br>n_wrk_drop                  0         0.00 N dropped work requests<br>n_backend                  11          .   N backends<br>
n_expired                 521          .   N expired objects<br>n_lru_nuked                 0          .   N LRU nuked objects<br>n_lru_saved                 0          .   N LRU saved objects<br>n_lru_moved           1257422          .   N LRU moved objects<br>
n_deathrow                  0          .   N objects on deathrow<br>losthdr                     0         0.00 HTTP header overflows<br>n_objsendfile               0         0.00 Objects sent with sendfile<br>n_objwrite           24858882       388.91 Objects sent with write<br>
n_objoverflow               0         0.00 Objects overflowing workspace<br>s_sess                9513431       148.84 Total Sessions<br>s_req               102670372      1606.26 Total Requests<br>s_pipe                     27         0.00 Total pipe<br>
s_pass                5716519        89.43 Total pass<br>s_fetch               5817878        91.02 Total fetch<br>s_hdrbytes        25797680938    403599.57 Total header bytes<br>s_bodybytes      274844776909   4299891.69 Total body bytes<br>
sess_closed           1141952        17.87 Session Closed<br>sess_pipeline           62084         0.97 Session Pipeline<br>sess_readahead          92195         1.44 Session Read Ahead<br>sess_linger         102206982      1599.01 Session Linger<br>
sess_herd            84599464      1323.54 Session herd<br>shm_records        3977250830     62223.30 SHM records<br>shm_writes          227215458      3554.74 SHM writes<br>shm_flushes                 2         0.00 SHM flushes due to overflow<br>
shm_cont               720671        11.27 SHM MTX contention<br>shm_cycles               1800         0.03 SHM cycles through buffer<br>sm_nreq                     0         0.00 allocator requests<br>sm_nobj                     0          .   outstanding allocations<br>
sm_balloc                   0          .   bytes allocated<br>sm_bfree                    0          .   bytes free<br>sma_nreq              3759248        58.81 SMA allocator requests<br>sma_nobj               209942          .   SMA outstanding allocations<br>
sma_nbytes         1685800871          .   SMA outstanding bytes<br>sma_balloc        30860533837          .   SMA bytes allocated<br>sma_bfree         29174732966          .   SMA bytes free<br>sms_nreq                 4896         0.08 SMS allocator requests<br>
sms_nobj                    0          .   SMS outstanding allocations<br>sms_nbytes                  0          .   SMS outstanding bytes<br>sms_balloc            2075904          .   SMS bytes allocated<br>sms_bfree             2075904          .   SMS bytes freed<br>
backend_req           5817885        91.02 Backend requests made<br>n_vcl                       1         0.00 N vcl total<br>n_vcl_avail                 1         0.00 N vcl available<br>n_vcl_discard               0         0.00 N vcl discarded<br>
n_purge                     1          .   N total active purges<br>n_purge_add                 1         0.00 N new purges added<br>n_purge_retire              0         0.00 N old purges deleted<br>n_purge_obj_test            0         0.00 N objects tested<br>
n_purge_re_test             0         0.00 N regexps tested against<br>n_purge_dups                0         0.00 N duplicate purges removed<br>hcb_nolock          102654743      1606.01 HCB Lookups without lock<br>hcb_lock                57436         0.90 HCB Lookups with lock<br>
hcb_insert              57436         0.90 HCB Inserts<br>esi_parse                   0         0.00 Objects ESI parsed (unlock)<br>esi_errors                  0         0.00 ESI parse errors (unlock)<br>accept_fail              1261         0.02 Accept failures<br>
client_drop_late            0         0.00 Connection dropped late<br>uptime                  63919         1.00 Client uptime<br><br>Thank you,<br>Roberto.<br><br><div class="gmail_quote">2011/1/12 Kristian Lyngstol <span dir="ltr"><<a href="mailto:kristian@varnish-software.com">kristian@varnish-software.com</a>></span><br>
<blockquote class="gmail_quote" style="margin: 0pt 0pt 0pt 0.8ex; border-left: 1px solid rgb(204, 204, 204); padding-left: 1ex;"><div class="im">On Wed, Jan 12, 2011 at 09:44:37AM -0300, Roberto O. Fernández Crisial wrote:<br>

> I expect Varnish request the object from webserver, show HIT and Age header<br>
> increase value.<br>
><br>
> This is the sequence right now:<br>
><br>
> 1) user ask for image<br>
> 2) varnish receive request<br>
> 3) varnish ask the webserver<br>
> 4) varnish cache the object<br>
> 5) varnish response user request<br>
> 6) varnish response users requests for 1800s (TTL)<br>
> 7) when TTL expires varnish should ask again webserver for the object and<br>
> cache it (but it doesn't)<br>
> 8) varnish response MISS for the object (Age header always shows value "0")<br>
> and ask webserver for every user request :(<br>
<br>
</div>Aha, it sounded like you were complaining that you got a (single) miss<br>
after the object expired. If you are getting multiple misses, it's a<br>
different story.<br>
<br>
If you attach varnishlog -o output of both the first miss that gets cached,<br>
a cache hit and the two first miss after it is expired, I'm pretty sure we<br>
can figure this out.<br>
<br>
Oh, and your VCL, and while we're at it, we might as well throw in<br>
varnishstat -1.<br>
<font color="#888888"><br>
- Kristian<br>
</font></blockquote></div><br>