varnish killing off the child process after a few minutes

Tung Nguyen tnguyen at bleacherreport.com
Tue Apr 7 22:01:51 CEST 2009


Hi guys,

We're on varnish 2.0.3

It looks like varnish restarts the child process for us every so often,
causing 503s :(.  Was wondering if this is a known issue.



######################################################################
 # ps auxww | grep varnishd
nobody    3385  0.0  0.3 8098024 7560 ?        Sl   19:49   0:00
/usr/sbin/varnishd -P /var/run/varnishd.pid -a :6081 -T localhost:6082 -p
sess_timeout 10 -p obj_workspace 8192 -p sess_workspace 32768 -p
listen_depth 8192 -p connect_timeout 1s -p thread_pool_min 100 -f
/etc/varnish/default.vcl
root      3938  0.0  0.0 111584   904 ?        Ss   Apr03   0:01
/usr/sbin/varnishd -P /var/run/varnishd.pid -a :6081 -T localhost:6082 -p
sess_timeout 10 -p obj_workspace 8192 -p sess_workspace 32768 -p
listen_depth 8192 -p connect_timeout 1s -p thread_pool_min 100 -f
/etc/varnish/default.vcl
root      3961  0.0  0.0   3884   672 pts/2    S<+  19:55   0:00 grep
--colour=auto varnishd
 #



######################################################################
 # varnishstat -1
uptime                    472          .   Child uptime
client_conn                40         0.08 Client connections accepted
client_req                100         0.21 Client requests received
cache_hit                   1         0.00 Cache hits
cache_hitpass               0         0.00 Cache hits for pass
cache_miss                 23         0.05 Cache misses
backend_conn               99         0.21 Backend connections success
backend_unhealthy            0         0.00 Backend connections not
attempted
backend_busy                0         0.00 Backend connections too many
backend_fail                0         0.00 Backend connections failures
backend_reuse              82         0.17 Backend connections reuses
backend_recycle            99         0.21 Backend connections recycles
backend_unused              0         0.00 Backend connections unused
n_srcaddr                   1          .   N struct srcaddr
n_srcaddr_act               0          .   N active struct srcaddr
n_sess_mem                 13          .   N struct sess_mem
n_sess                      1          .   N struct sess
n_object                   23          .   N struct object
n_objecthead               29          .   N struct objecthead
n_smf                      47          .   N struct smf
n_smf_frag                  0          .   N small free smf
n_smf_large                 1          .   N large free smf
n_vbe_conn                  6          .   N struct vbe_conn
n_bereq                     6          .   N struct bereq
n_wrk                     200          .   N worker threads
n_wrk_create              200         0.42 N worker threads created
n_wrk_failed                0         0.00 N worker threads not created
n_wrk_max               13326        28.23 N worker threads limited
n_wrk_queue                 0         0.00 N queued work requests
n_wrk_overflow              0         0.00 N overflowed work requests
n_wrk_drop                  0         0.00 N dropped work requests
n_backend                   2          .   N backends
n_expired                   0          .   N expired objects
n_lru_nuked                 0          .   N LRU nuked objects
n_lru_saved                 0          .   N LRU saved objects
n_lru_moved                 1          .   N LRU moved objects
n_deathrow                  0          .   N objects on deathrow
losthdr                     0         0.00 HTTP header overflows
n_objsendfile               0         0.00 Objects sent with sendfile
n_objwrite                 65         0.14 Objects sent with write
n_objoverflow               0         0.00 Objects overflowing workspace
s_sess                     40         0.08 Total Sessions
s_req                     100         0.21 Total Requests
s_pipe                      0         0.00 Total pipe
s_pass                     76         0.16 Total pass
s_fetch                    99         0.21 Total fetch
s_hdrbytes              35654        75.54 Total header bytes
s_bodybytes            206284       437.04 Total body bytes
sess_closed                 0         0.00 Session Closed
sess_pipeline               0         0.00 Session Pipeline
sess_readahead              0         0.00 Session Read Ahead
sess_linger                 0         0.00 Session Linger
sess_herd                 100         0.21 Session herd
shm_records              9594        20.33 SHM records
shm_writes               1884         3.99 SHM writes
shm_flushes                 0         0.00 SHM flushes due to overflow
shm_cont                   10         0.02 SHM MTX contention
shm_cycles                  0         0.00 SHM cycles through buffer
sm_nreq                   186         0.39 allocator requests
sm_nobj                    46          .   outstanding allocations
sm_balloc              425984          .   bytes allocated
sm_bfree           6431973376          .   bytes free
sma_nreq                    0         0.00 SMA allocator requests
sma_nobj                    0          .   SMA outstanding allocations
sma_nbytes                  0          .   SMA outstanding bytes
sma_balloc                  0          .   SMA bytes allocated
sma_bfree                   0          .   SMA bytes free
sms_nreq                    0         0.00 SMS allocator requests
sms_nobj                    0          .   SMS outstanding allocations
sms_nbytes                  0          .   SMS outstanding bytes
sms_balloc                  0          .   SMS bytes allocated
sms_bfree                   0          .   SMS bytes freed
backend_req                99         0.21 Backend requests made
n_vcl                       1         0.00 N vcl total
n_vcl_avail                 1         0.00 N vcl available
n_vcl_discard               0         0.00 N vcl discarded
n_purge                     1          .   N total active purges
n_purge_add                 1         0.00 N new purges added
n_purge_retire              0         0.00 N old purges deleted
n_purge_obj_test            0         0.00 N objects tested
n_purge_re_test             0         0.00 N regexps tested against
n_purge_dups                0         0.00 N duplicate purges removed
hcb_nolock                  0         0.00 HCB Lookups without lock
hcb_lock                    0         0.00 HCB Lookups with lock
hcb_insert                  0         0.00 HCB Inserts
esi_parse                   0         0.00 Objects ESI parsed (unlock)
esi_errors                  0         0.00 ESI parse errors (unlock)



######################################################################
# I can see that the threads are starting back up in varnishlog
######################################################################

8 RxHeader     c Accept-Language: en-us,en;q=0.5
 8 RxHeader     c Accept-Encoding: gzip,deflate
 8 RxHeader     c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
 8 RxHeader     c Keep-Alive: 300
 8 RxHeader     c Connection: keep-alive
 8 RxHeader     c Referer: http://stagingbleacherreport.com/nascar
 8 RxHeader     c Cookie:
__utma=58205160.3272659617253579300.1238530464.1239125976.1239133102.21;
__utmz=58205160.1238530464.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
__qca=1238530467-23581915-71188578;
auth_token=4c078f7b1d3097b170260c6978c9862c; pod_151314=Mon+
 8 RxHeader     c If-None-Match: "004e69938cfe6ed16863cc156a0e9b34"
 8 VCL_call     c recv
 8 VCL_return   c pass
 8 VCL_call     c pass
 8 VCL_return   c pass
 8 VCL_call     c error
 8 VCL_return   c deliver
 8 Length       c 465
 8 VCL_call     c deliver
 8 VCL_return   c deliver
 8 TxProtocol   c HTTP/1.1
 8 TxStatus     c 503
 8 TxResponse   c Service Unavailable
 8 TxHeader     c Server: Varnish
 8 TxHeader     c Retry-After: 0
 8 TxHeader     c Content-Type: text/html; charset=utf-8
 8 TxHeader     c Content-Length: 465
 8 TxHeader     c Date: Tue, 07 Apr 2009 19:49:47 GMT
 8 TxHeader     c X-Varnish: 171071333
 8 TxHeader     c Age: 0
 8 TxHeader     c Via: 1.1 varnish
 8 TxHeader     c Connection: close
 8 TxHeader     c X-Cache: MISS
 8 ReqEnd       c 171071333 1239133787.063603163 1239133787.063603163
0.000000000 0.000000000 0.000000000
 8 SessionClose c error
 8 StatSess     c 67.164.99.232 59479 0 1 1 0 1 0 249 465
 0 StatAddr     - 67.164.99.232 0 0 1 1 0 1 0 249 465
 0 WorkThread   - 0x55028bd0 start
 0 WorkThread   - 0x55829bd0 start
 0 WorkThread   - 0x5602abd0 start
 0 WorkThread   - 0x5682bbd0 start
 0 WorkThread   - 0x5702cbd0 start
 0 WorkThread   - 0x5782dbd0 start
 0 WorkThread   - 0x5802ebd0 start
 0 WorkThread   - 0x5882fbd0 start
 0 WorkThread   - 0x59030bd0 start
 0 WorkThread   - 0x59831bd0 start
 0 WorkThread   - 0x5a032bd0 start
 0 WorkThread   - 0x5a833bd0 start
 0 WorkThread   - 0x5b034bd0 start
 0 WorkThread   - 0x5b835bd0 start
 0 WorkThread   - 0x5c036bd0 start
 0 WorkThread   - 0x5c837bd0 start
 0 WorkThread   - 0x5d038bd0 start
 0 Backend_health - A1 Back healthy 4--X-S-RH 2 2 5 0.000000 0.000000
HTTP/1.1 200 OK
 0 Backend_health - A2 Back healthy 4--X-S-RH 2 2 5 0.000000 0.000000
HTTP/1.1 200 OK
 0 WorkThread   - 0x5d839bd0 start
 0 WorkThread   - 0x5e03abd0 start
 0 WorkThread   - 0x5e83bbd0 start
 0 WorkThread   - 0x5f03cbd0 start
 0 WorkThread   - 0x5f83dbd0 start
 0 WorkThread   - 0x6003ebd0 start
 0 WorkThread   - 0x6083fbd0 start
 0 WorkThread   - 0x61040bd0 start

#

######################################################################
# heres are default.vcl
cat /etc/varnish/default.vcl
backend A1 {
    .host = "ey03-s00344";
    .port = "80";
    .probe = {
        .interval = 1s;
        .timeout = 3 s;
        .window = 5;
        .threshold = 2;
        .url = "http://stagingbleacherreport.com/images/blank.gif";
    }
}

backend A2 {
    .host = "ey03-s00344";
    .port = "80";
    .probe = {
        .interval = 1s;
        .timeout = 3 s;
        .window = 5;
        .threshold = 2;
        .url = "http://stagingbleacherreport.com/images/blank.gif";
    }
}

director www_director round-robin {
    {  .backend = A1; }
    {  .backend = A2; }
}


acl local {
        "localhost";
}

C{ #include <syslog.h> }C
sub vcl_recv {

    C{ syslog(LOG_INFO, "@@@@ vcl_recv."); }C
    C{ syslog(LOG_INFO, VRT_r_req_url(sp)); }C

    set req.backend = www_director ;

    # Add a unique header containing the client address
    remove req.http.X-Forwarded-For;
    set    req.http.X-Forwarded-For = client.ip;

    /* clear cookies on feeds */
    if (req.url ~ "^/articles[;/]feed") {
        C{ syslog(LOG_INFO, "@@@@ feed."); }C
unset req.http.Cookie;
        lookup;
    }

    # cache assets
    if (req.url ~ "^/images/" || req.url ~ "^/javascripts" || req.url ~
"^/stylesheets") {
        C{ syslog(LOG_INFO, "@@@@ assets."); }C
unset req.http.Cookie;
        lookup;
    }

    # do not cache images_root
    if (req.url ~ "^/images_root") {
        C{ syslog(LOG_INFO, "@@@@ images_root."); }C
        pass;
    }

    if (req.request == "PURGE") {
            if (!client.ip ~ local) {
                    error 405 "Not allowed.";
            }
            lookup;
    }
   C{ syslog(LOG_INFO, "@@@@ fallthrough."); }C
}

#sub vcl_pipe {
#     # If we don't set the Connection: close header, any following
#     # requests from the client will also be piped through and
#     # left untouched by varnish. We don't want that.
#     set bereq.http.connection = "close";
#}

sub vcl_fetch {
    if (req.url ~ "^/articles[;/]feed") {
        unset obj.http.Set-Cookie;
        unset obj.http.expires;
        set obj.ttl = 60m;
        deliver;
    }

    if (req.url ~ "^/images/" || req.url ~ "^/javascripts" || req.url ~
"^/stylesheets") {
        unset obj.http.Set-Cookie;
        set obj.ttl = 30m;
    }

    # similar to what twitter uses
    if (!obj.cacheable) {
            set obj.http.X-Cacheable = "NO:Not-Cacheable";
            pass;
    }
    if (obj.http.Cache-Control ~ "private") {
            if(req.http.Cookie ~"(UserID|_session)") {
                    set obj.http.X-Cacheable = "NO:Got Session";
            } else {
                    set obj.http.X-Cacheable = "NO:Cache-Control=private";
            }
            pass;
    }
    if (obj.http.Set-Cookie ~ "(UserID|_session)") {
            set obj.http.X-Cacheable = "NO:Set-Cookie";
            pass;
    }

    set obj.grace = 30s;  # only one slow requests during cache misses
}

sub vcl_hit {
        if (req.request == "PURGE") {
                set obj.ttl = 0s;
                error 200 "Purged.";
        }
}

sub vcl_miss {
        if (req.request == "PURGE") {
                error 404 "Not in cache.";
        }
}

sub vcl_deliver {
        if (obj.hits > 0) {
                set resp.http.X-Cache = "HIT";
        } else {
                set resp.http.X-Cache = "MISS";
        }
}



Thanks,
Tung
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20090407/d40d36c2/attachment-0001.html>


More information about the varnish-misc mailing list