requests keep timing out

Tung Nguyen tnguyen at bleacherreport.com
Wed Apr 1 16:47:51 CEST 2009


Here's the full varnishstat -1

varnishstat -1
uptime                    212          .   Child uptime
client_conn              1518         7.16 Client connections accepted
client_req               5662        26.71 Client requests received
cache_hit                3230        15.24 Cache hits
cache_hitpass               8         0.04 Cache hits for pass
cache_miss                561         2.65 Cache misses
backend_conn             2307        10.88 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            1920         9.06 Backend connections reuses
backend_recycle          2038         9.61 Backend connections recycles
backend_unused              0         0.00 Backend connections unused
n_srcaddr                 365          .   N struct srcaddr
n_srcaddr_act               0          .   N active struct srcaddr
n_sess_mem                952          .   N struct sess_mem
n_sess                      1          .   N struct sess
n_object                  750          .   N struct object
n_objecthead             1079          .   N struct objecthead
n_smf                    1272          .   N struct smf
n_smf_frag                 98          .   N small free smf
n_smf_large                 2          .   N large free smf
n_vbe_conn                  4          .   N struct vbe_conn
n_bereq                    88          .   N struct bereq
n_wrk                    1600          .   N worker threads
n_wrk_create             1600         7.55 N worker threads created
n_wrk_failed                0         0.00 N worker threads not created
n_wrk_max                   0         0.00 N worker threads limited
n_wrk_queue                 0         0.00 N queued work requests
n_wrk_overflow            980         4.62 N overflowed work requests
n_wrk_drop                  0         0.00 N dropped work requests
n_backend                   6          .   N backends
n_expired                  54          .   N expired objects
n_lru_nuked                 0          .   N LRU nuked objects
n_lru_saved                 0          .   N LRU saved objects
n_lru_moved               833          .   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               4589        21.65 Objects sent with write
n_objoverflow               0         0.00 Objects overflowing workspace
s_sess                   1517         7.16 Total Sessions
s_req                    5662        26.71 Total Requests
s_pipe                      0         0.00 Total pipe
s_pass                   1871         8.83 Total pass
s_fetch                  2307        10.88 Total fetch
s_hdrbytes            1673491      7893.83 Total header bytes
s_bodybytes          26560497    125285.36 Total body bytes
sess_closed               249         1.17 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                5428        25.60 Session herd
shm_records            308891      1457.03 SHM records
shm_writes              20426        96.35 SHM writes
shm_flushes                 0         0.00 SHM flushes due to overflow
shm_cont                   14         0.07 SHM MTX contention
shm_cycles                  0         0.00 SHM cycles through buffer
sm_nreq                  5117        24.14 allocator requests
sm_nobj                  1172          .   outstanding allocations
sm_balloc            10076160          .   bytes allocated
sm_bfree           5983641600          .   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                  125         0.59 SMS allocator requests
sms_nobj                    0          .   SMS outstanding allocations
sms_nbytes                  0          .   SMS outstanding bytes
sms_balloc              58250          .   SMS bytes allocated
sms_bfree               58250          .   SMS bytes freed
backend_req              2307        10.88 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)

Tung


On Wed, Apr 1, 2009 at 7:24 AM, Tung Nguyen <tnguyen at bleacherreport.com>wrote:

> Hey guys,
>
> Our requests seem to be getting timed out.  I set all the timeout
> parameters pretty high, so wondering what could be causing it.
>
> Also, how do I check out the number of current threads being used in
> varnishstat?
>
> Thanks,
> Tung
>
> # ps auxww | grep varnish
> root      2649  0.0  2.4 101776 82744 pts/0    S<   13:48   0:00 varnishlog
> -w varnish.log
> root      4301  0.0  0.0 110552  1136 ?        S<s  14:05   0:00
> /usr/sbin/varnishd -P /var/run/varnishd.pid -a :6081 -T localhost:6082 -p
> sess_timeout 25 -p obj_workspace 8192 -p sess_workspace 32768 -p
> listen_depth 8192 -p connect_timeout 3s -p thread_pool_min 100 -f
> /etc/varnish/default.vcl
> nobody    4302  0.0  1.1 7781688 39468 ?       S<l  14:05   0:00
> /usr/sbin/varnishd -P /var/run/varnishd.pid -a :6081 -T localhost:6082 -p
> sess_timeout 25 -p obj_workspace 8192 -p sess_workspace 32768 -p
> listen_depth 8192 -p connect_timeout 3s -p thread_pool_min 100 -f
> /etc/varnish/default.vcl
> root      4872  0.0  0.0   3876   556 pts/0    R<+  14:22   0:00 grep
> --colour=auto varnish
> #
>
>
>     0 VCL_call     - prefetch
>     0 VCL_return   - fetch
>     0 Debug        - "Attempt Prefetch 1804102565"
>     0 Backend_health - A3 Still healthy 4--X-S-RH 5 3 5 0.000000 0.000000
> HTTP/1.1 200 OK
>     0 Backend_health - A1 Still healthy 4--X-S-RH 5 3 5 0.000000 0.001500
> HTTP/1.1 200 OK
>     0 Backend_health - A6 Still healthy 4--X-S-RH 5 3 5 0.000000 0.000001
> HTTP/1.1 200 OK
>     0 Backend_health - A2 Still healthy 4--X-S-RH 5 3 5 0.000000 0.000000
> HTTP/1.1 200 OK
>     0 Backend_health - A4 Still healthy 4--X-S-RH 5 3 5 0.000000 0.000042
> HTTP/1.1 200 OK
>     0 ExpPick      - 1804096341 ttl
>     0 VCL_call     - timeout
>     0 VCL_return   - discard
>     0 ExpKill      - 1804096341 -30
>     0 ExpPick      - 1804096350 ttl
>     0 VCL_call     - timeout
>     0 VCL_return   - discard
>     0 ExpKill      - 1804096350 -30
>     0 ExpPick      - 1804096354 ttl
>     0 VCL_call     - timeout
>     0 VCL_return   - discard
>     0 ExpKill      - 1804096354 -30
>     0 ExpPick      - 1804096376 ttl
>     0 VCL_call     - timeout
>     0 VCL_return   - discard
>     0 ExpKill      - 1804096376 -30
>     0 ExpPick      - 1804096384 ttl
>     0 VCL_call     - timeout
>     0 VCL_return   - discard
>     0 ExpKill      - 1804096384 -30
>     0 CLI          - Rd ping
>     0 CLI          - Wr 0 200 PONG 1238593700 1.0
>     0 Backend_health - A5 Still healthy 4--X-S-RH 5 3 5 0.000000 0.000000
> HTTP/1.1 200 OK
>     0 ExpPick      - 1804102829 prefetch
>     0 VCL_call     - prefetch
>     0 VCL_return   - fetch
>     0 Debug        - "Attempt Prefetch 1804102829"
>     0 Backend_health - A3 Still healthy 4--X-S-RH 5 3 5 0.000000 0.000000
> HTTP/1.1 200 OK
>     0 Backend_health - A1 Still healthy 4--X-S-RH 5 3 5 0.000000 0.001125
> HTTP/1.1 200 OK
>     0 Backend_health - A6 Still healthy 4--X-S-RH 5 3 5 0.000000 0.000001
> HTTP/1.1 200 OK
>     0 Backend_health - A2 Still healthy 4--X-S-RH 5 3 5 0.000000 0.000000
> HTTP/1.1 200 OK
>     0 Backend_health - A4 Still healthy 4--X-S-RH 5 3 5 0.000000 0.000032
> HTTP/1.1 200 OK
>     0 CLI          - Rd ping
>     0 CLI          - Wr 0 200 PONG 1238593703 1.0
>     0 ExpPick      - 1803925354 ttl
>     0 VCL_call     - timeout
>
>
> param.show
> 200 2137
> accept_fd_holdoff          50 [ms]
> acceptor                   default (epoll, poll)
> auto_restart               on [bool]
> backend_http11             on [bool]
> between_bytes_timeout      60.000000 [s]
> cache_vbe_conns            off [bool]
> cc_command                 "exec cc -fpic -shared -Wl,-x -o %o %s"
> cli_buffer                 8192 [bytes]
> cli_timeout                5 [seconds]
> client_http11              off [bool]
> clock_skew                 10 [s]
> connect_timeout            1.000000 [s]
> default_grace              10
> default_ttl                120 [seconds]
> diag_bitmap                0x0 [bitmap]
> err_ttl                    0 [seconds]
> esi_syntax                 0 [bitmap]
> fetch_chunksize            128 [kilobytes]
> first_byte_timeout         60.000000 [s]
> group                      nobody (65534)
> listen_address             :6081
> listen_depth               8192 [connections]
> log_hashstring             off [bool]
> log_local_address          off [bool]
> lru_interval               2 [seconds]
> max_esi_includes           5 [includes]
> max_restarts               4 [restarts]
> obj_workspace              8192 [bytes]
> overflow_max               100 [%]
> ping_interval              3 [seconds]
> pipe_timeout               60 [seconds]
> prefer_ipv6                off [bool]
> purge_dups                 off [bool]
> purge_hash                 on [bool]
> rush_exponent              3 [requests per request]
> send_timeout               600 [seconds]
> sess_timeout               10 [seconds]
> sess_workspace             32768 [bytes]
> session_linger             0 [ms]
> shm_reclen                 255 [bytes]
> shm_workspace              8192 [bytes]
> srcaddr_hash               1049 [buckets]
> srcaddr_ttl                30 [seconds]
> thread_pool_add_delay      20 [milliseconds]
> thread_pool_add_threshold  2 [requests]
> thread_pool_fail_delay     200 [milliseconds]
> thread_pool_max            500 [threads]
> thread_pool_min            100 [threads]
> thread_pool_purge_delay    1000 [milliseconds]
> thread_pool_timeout        300 [seconds]
> thread_pools               2 [pools]
> user                       nobody (65534)
> vcl_trace                  off [bool]
>
>
>
> 0+00:01:23                                                                                         ey03-s00419
> Hitrate ratio:        4        4        4
> Hitrate avg:     0.7154   0.7154   0.7154
>
>
>         2111         0.00        25.43 Client connections accepted
>
>         8315         0.00       100.18 Client requests received
>
>         5019         0.00        60.47 Cache hits
>
>            6         0.00         0.07 Cache hits for pass
>
>          805         0.00         9.70 Cache misses
>
>         2848         0.00        34.31 Backend connections success
>
>         2471         0.00        29.77 Backend connections reuses
>
>         2691         0.00        32.42 Backend connections recycles
>
>          456          .            .   N struct srcaddr
>
>           27          .            .   N active struct srcaddr
>
>          995          .            .   N struct sess_mem
>
>           55          .            .   N struct sess
>
>          584          .            .   N struct object
>
>          670          .            .   N struct objecthead
>
>         1147          .            .   N struct smf
>
>            1          .            .   N small free smf
>
>            1          .            .   N large free smf
>
>            6          .            .   N struct vbe_conn
>
>           22          .            .   N struct bereq
>
>          200          .            .   N worker threads
>
>          200         0.00         2.41 N worker threads created
>
>           57         0.00         0.69 N overflowed work requests
>
>            6          .            .   N backends
>
>         2046          .            .   N LRU moved objects
>
>         6277         0.00        75.63 Objects sent with write
>
>         2110         0.00        25.42 Total Sessions
>
>         8314         0.00       100.17 Total Requests
>
>         2491         0.00        30.01 Total pass
>
>         2847         0.00        34.30 Total fetch
>
>      2410204         0.00     29038.60 Total header bytes
>
>     38160409         0.00    459763.96 Total body bytes
>
>          605         0.00         7.29 Session Closed
>
>            2         0.00         0.02 Session Pipeline
>
>            6         0.00         0.07 Session Read Ahead
>
>         7734         0.00        93.18 Session herd
>
>       428358        12.00      5160.94 SHM records
>
>        26190        12.00       315.54 SHM writes
>
>            2         0.00         0.02 SHM MTX contention
>
>         6378         0.00        76.84 allocator requests
>
>         1145          .            .   outstanding allocations
>
>     12103680          .            .   bytes allocated
>
>   6028206080          .            .   bytes free
>
>          448         0.00         5.40 SMS allocator requests
>
>       208768          .            .   SMS bytes allocated
>
>       208768          .            .   SMS bytes freed
>
>         2848         0.00        34.31 Backend requests made
>
>            1         0.00         0.01 N vcl total
>
>            1         0.00         0.01 N vcl available
>
>            1          .            .   N total active purges
>
>            1         0.00         0.01 N new purges added
>
>
>
>
> Thanks,
> Tung
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20090401/8ad8566e/attachment-0001.html>


More information about the varnish-misc mailing list