[Varnish] #538: [varnish-2.0.4] Potential Memory Leak

Varnish varnish-bugs at projects.linpro.no
Thu Nov 5 16:46:40 CET 2009


#538: [varnish-2.0.4] Potential Memory Leak
-------------------------------+--------------------------------------------
 Reporter:  pprocacci          |        Owner:  phk  
     Type:  defect             |       Status:  new  
 Priority:  high               |    Milestone:       
Component:  varnishd           |      Version:  trunk
 Severity:  major              |   Resolution:       
 Keywords:  Memory Leak 2.0.4  |  
-------------------------------+--------------------------------------------
Comment (by olau):

 I think I have the same leak. Varnish has been dying lately, apparently
 without reason. I had to setup a monitor process to restart it, in spite
 of the manager architecture. I'm using really simple VCL.

 I'm on a 32 bit 4-core Linux server (2.6.9). Here's top:

 {{{
   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 24092 nobody    16   0  586m 273m 269m S    0  3.4   1:01.59 varnishd
 }}}

 Note 273 MB resident. And virtual memory is more than the 300 MB file
 allocated:

 {{{
 /usr/sbin/varnishd -d -d -a :80 -T 127.0.0.1:6082 -t 15 -f
 /etc/varnish/iola.vcl -s file,/tmp/varnish_storage.bin,300M
 }}}

 Here's my .vcl, simple, two backends and a bit of regexp:

 {{{
 backend default {
   .host = "xxx.xxx.xxx.xxx";
   .port = "xxxx";
 }

 backend lighttpd {
   .host = "xxx.xxx.xxx.xxx";
   .port = "xxxx";
 }

 sub vcl_recv {
     if (req.http.host ~ "media.*" || req.url ~ "^/media/") {
        set req.backend = lighttpd;
        pass;
     }

     if (req.http.host ~ "people.iola.dk") {
        set req.backend = lighttpd;
        pass;
     }

     if (req.request == "GET" && req.http.Cookie) {
        lookup;
     }
 }
 }}}

 Output from varnishstat -1, the cache looks like it's almost empty, only
 266 kb allocated (low timeout, not much traffic), strangely there's
 actually a purge request in there (?), I'm sure I haven't added that:
 {{{
 uptime                 167638          .   Child uptime
 client_conn             34227         0.20 Client connections accepted
 client_req              67452         0.40 Client requests received
 cache_hit                 789         0.00 Cache hits
 cache_hitpass               0         0.00 Cache hits for pass
 cache_miss              12605         0.08 Cache misses
 backend_conn            66680         0.40 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           45604         0.27 Backend connections reuses
 backend_recycle         60551         0.36 Backend connections recycles
 backend_unused              0         0.00 Backend connections unused
 n_srcaddr                1022          .   N struct srcaddr
 n_srcaddr_act               4          .   N active struct srcaddr
 n_sess_mem                 82          .   N struct sess_mem
 n_sess                     11          .   N struct sess
 n_object                    4          .   N struct object
 n_objecthead               43          .   N struct objecthead
 n_smf                      12          .   N struct smf
 n_smf_frag                  3          .   N small free smf
 n_smf_large                 1          .   N large free smf
 n_vbe_conn                  3          .   N struct vbe_conn
 n_bereq                    22          .   N struct bereq
 n_wrk                      10          .   N worker threads
 n_wrk_create               46         0.00 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            308         0.00 N overflowed work requests
 n_wrk_drop                  0         0.00 N dropped work requests
 n_backend                   2          .   N backends
 n_expired               12603          .   N expired objects
 n_lru_nuked                 0          .   N LRU nuked objects
 n_lru_saved                 0          .   N LRU saved objects
 n_lru_moved               634          .   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              59979         0.36 Objects sent with write
 n_objoverflow               0         0.00 Objects overflowing workspace
 s_sess                  34225         0.20 Total Sessions
 s_req                   67468         0.40 Total Requests
 s_pipe                      0         0.00 Total pipe
 s_pass                  54074         0.32 Total pass
 s_fetch                 66619         0.40 Total fetch
 s_hdrbytes           19646304       117.19 Total header bytes
 s_bodybytes        2546177291     15188.54 Total body bytes
 sess_closed              5558         0.03 Session Closed
 sess_pipeline             197         0.00 Session Pipeline
 sess_readahead             37         0.00 Session Read Ahead
 sess_linger                 0         0.00 Session Linger
 sess_herd               61934         0.37 Session herd
 shm_records           5002142        29.84 SHM records
 shm_writes             423864         2.53 SHM writes
 shm_flushes                98         0.00 SHM flushes due to overflow
 shm_cont                  130         0.00 SHM MTX contention
 shm_cycles                  2         0.00 SHM cycles through buffer
 sm_nreq                127688         0.76 allocator requests
 sm_nobj                     8          .   outstanding allocations
 sm_balloc              266240          .   bytes allocated
 sm_bfree            314306560          .   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                   60         0.00 SMS allocator requests
 sms_nobj                    0          .   SMS outstanding allocations
 sms_nbytes                  0          .   SMS outstanding bytes
 sms_balloc              27900          .   SMS bytes allocated
 sms_bfree               27900          .   SMS bytes freed
 backend_req             66681         0.40 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)
 }}}

 The log has some dead children:
 {{{
 ...
 socket(): Address family not supported by protocol
 child (20094) Started
 Child (20094) said Closed fds: 4 6 9 10 12 13
 Child (20094) said Child starts
 Child (20094) said managed to mmap 314572800 bytes of 314572800
 Child (20094) said Ready
 Child (20094) not responding to ping, killing it.
 Child (20094) died signal=3
 Child cleanup complete
 socket(): Address family not supported by protocol
 child (27662) Started
 Child (27662) said Closed fds: 4 6 9 10 12 13
 Child (27662) said Child starts
 Child (27662) said managed to mmap 314572800 bytes of 314572800
 Child (27662) said Ready
 Child (27662) not responding to ping, killing it.
 Child (27662) died signal=3
 Child cleanup complete
 socket(): Address family not supported by protocol
 child (11809) Started
 Child (11809) said Closed fds: 4 6 9 10 12 13
 Child (11809) said Child starts
 Child (11809) said managed to mmap 314572800 bytes of 314572800
 Child (11809) said Ready
 Child (11809) not responding to ping, killing it.
 Child (11809) died signal=3
 Child cleanup complete
 socket(): Address family not supported by protocol
 child (24092) Started
 Child (24092) said Closed fds: 4 6 9 10 12 13
 Child (24092) said Child starts
 Child (24092) said managed to mmap 314572800 bytes of 314572800
 Child (24092) said Ready
 }}}

-- 
Ticket URL: <http://varnish.projects.linpro.no/ticket/538#comment:6>
Varnish <http://varnish.projects.linpro.no/>
The Varnish HTTP Accelerator


More information about the varnish-bugs mailing list