Re: varnish killing off the child process after a few minutes

2009-04-08 Thread Kristian Lyngstol
On Tue, Apr 07, 2009 at 01:01:51PM -0700, Tung Nguyen wrote:
 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.

Can you check the syslog for any more information?

-- 
Kristian LyngstĂžl
Redpill Linpro AS
Tlf: +47 21544179
Mob: +47 99014497


pgp9e6JrQxoi6.pgp
Description: PGP signature
___
varnish-misc mailing list
varnish-misc@projects.linpro.no
http://projects.linpro.no/mailman/listinfo/varnish-misc


Re: varnish killing off the child process after a few minutes

2009-04-08 Thread Tung Nguyen
Sure,
Here's the syslog around one of the times when the child looks like its
crashing.


Apr  8 01:19:00 ey03-s00344 varnishd[2628]:  assets.
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:  vcl_recv.
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:
/javascripts/responders_1239147022.js?1239147050
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:  assets.
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:  vcl_recv.
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:
/images/shared/nav/dropdown-arrow.jpg
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:  assets.
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:  vcl_recv.
Apr  8 01:19:00 ey03-s00344 varnishd[2628]: /images/shared/nav/rnd-left.jpg
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:  assets.
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:  vcl_recv.
Apr  8 01:19:00 ey03-s00344 varnishd[2628]: /images/shared/nav/rnd-right.jpg
Apr  8 01:19:00 ey03-s00344 varnishd[2628]:  assets.
Apr  8 01:19:01 ey03-s00344 cron[3661]: (bleacherreport) CMD (ruby
/var/bleacherreport/current/bin/hit_counts.rb every_minute RAILS_ENV=staging
1 /var/bleacherreport/current/log/cron_wrapper.log 21)
Apr  8 01:19:15 ey03-s00344 varnishd[2628]:  vcl_recv.
Apr  8 01:19:15 ey03-s00344 kernel: [30326523.602151] varnishd[2740] general
protection rip:2ac1df7c5b26 rsp:75062798 error:0
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (2628) died signal=11
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child cleanup complete
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: child (3670) Started
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said Closed fds: 3
5 6 7 12 13 15 16
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said Child starts
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said managed to
mmap 6432399360 bytes of 6432399360
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said Ready
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said Probe(GET
http://stagingbleacherreport.com/images/blank.gif HTTP/1.1
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said Host:
ey03-s00344
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said Connection:
close
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said
Apr  8 01:19:15 ey03-s00344 last message repeated 2 times
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said , 3, 1)
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said Probe(GET
http://stagingbleacherreport.com/images/blank.gif HTTP/1.1
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said Host:
ey03-s00344
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said Connection:
close
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said
Apr  8 01:19:15 ey03-s00344 last message repeated 2 times
Apr  8 01:19:15 ey03-s00344 varnishd[3938]: Child (3670) said , 3, 1)
Apr  8 01:19:18 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:18 ey03-s00344 varnishd[3670]: /mlb/games/85
Apr  8 01:19:18 ey03-s00344 varnishd[3670]:  fallthrough.
Apr  8 01:19:19 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:19 ey03-s00344 varnishd[3670]:
/javascripts/base_1239147022.js?1239147049
Apr  8 01:19:19 ey03-s00344 varnishd[3670]:  assets.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:
/javascripts/core_1239147022.js?1239147049
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  assets.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]: /images/hat/br_icon.jpg
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  assets.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]: /images/shared/bkg-content.jpg
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  assets.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]: /images/sprites/forms.jpg
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  assets.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:
/images/search_indicator.gif?1239147022
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  assets.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]: /images/search_bg.png
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  assets.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]: /images/logo_new.gif
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  assets.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  vcl_recv.
Apr  8 01:19:21 ey03-s00344 varnishd[3670]: /images/shared/nav/bkg-nav.jpg
Apr  8 01:19:21 ey03-s00344 varnishd[3670]:  assets.
Apr  8 01:19:21 

varnish killing off the child process after a few minutes

2009-04-07 Thread Tung Nguyen
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
nobody3385  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/2S+  19:55   0:00 grep
--colour=auto varnishd
 #



##
 # varnishstat -1
uptime472  .   Child uptime
client_conn40 0.08 Client connections accepted
client_req100 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_unhealthy0 0.00 Backend connections not
attempted
backend_busy0 0.00 Backend connections too many
backend_fail0 0.00 Backend connections failures
backend_reuse  82 0.17 Backend connections reuses
backend_recycle99 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_failed0 0.00 N worker threads not created
n_wrk_max   1332628.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_fetch99 0.21 Total fetch
s_hdrbytes  3565475.54 Total header bytes
s_bodybytes206284   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  959420.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_nobj46  .   outstanding allocations
sm_balloc  425984  .   bytes allocated
sm_bfree   6431973376  .   bytes free
sma_nreq0 0.00 SMA allocator