Resending the other attachments (syslog and varnishstat) -T
On Tue, Mar 22, 2011 at 11:44 PM, Tejaswi Nadahalli <[email protected]>wrote: > The child process got killed abruptly. > > I am attaching a bunch of munin graphs, relevant syslog, the current > varnishstat -1 output. > > I am running Varnish 2.1.5 on a 64 bit machine with the following command: > > sudo varnishd -f /etc/varnish/default.vcl -s malloc,5G -T 127.0.0.1:2000-a > 0.0.0.0:80 -p thread_pools=2 -p thread_pool_min=100 -p > thread_pool_max=5000 -p thread_pool_add_delay=2 -p cli_timeout=25 -p > session_linger=100 -p lru_interval=20 -p listen_depth=4096 -t 31536000 > > My VCL is fairly simple, and I think has nothing to do with the error. > > Any help would be appreciated. > > -T > > > >
client_conn 5409469 482.69 Client connections accepted client_drop 0 0.00 Connection dropped, no sess/wrk client_req 5409469 482.69 Client requests received cache_hit 5358032 478.10 Cache hits cache_hitpass 0 0.00 Cache hits for pass cache_miss 51434 4.59 Cache misses backend_conn 51434 4.59 Backend conn. success backend_unhealthy 0 0.00 Backend conn. not attempted backend_busy 0 0.00 Backend conn. too many backend_fail 0 0.00 Backend conn. failures backend_reuse 0 0.00 Backend conn. reuses backend_toolate 0 0.00 Backend conn. was closed backend_recycle 0 0.00 Backend conn. recycles backend_unused 0 0.00 Backend conn. unused fetch_head 0 0.00 Fetch head fetch_length 51433 4.59 Fetch with Length fetch_chunked 0 0.00 Fetch chunked fetch_eof 0 0.00 Fetch EOF fetch_bad 0 0.00 Fetch had bad headers fetch_close 0 0.00 Fetch wanted close fetch_oldhttp 0 0.00 Fetch pre HTTP/1.1 closed fetch_zero 0 0.00 Fetch zero len fetch_failed 0 0.00 Fetch failed n_sess_mem 200 . N struct sess_mem n_sess 100 . N struct sess n_object 45560 . N struct object n_vampireobject 0 . N unresurrected objects n_objectcore 45669 . N struct objectcore n_objecthead 45673 . N struct objecthead n_smf 0 . N struct smf n_smf_frag 0 . N small free smf n_smf_large 0 . N large free smf n_vbe_conn 0 . N struct vbe_conn n_wrk 200 . N worker threads n_wrk_create 200 0.02 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 28 0.00 N overflowed work requests n_wrk_drop 0 0.00 N dropped work requests n_backend 3 . N backends n_expired 5763 . N expired objects n_lru_nuked 0 . N LRU nuked objects n_lru_saved 0 . N LRU saved objects n_lru_moved 298470 . 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 5409362 482.68 Objects sent with write n_objoverflow 0 0.00 Objects overflowing workspace s_sess 5409469 482.69 Total Sessions s_req 5409469 482.69 Total Requests s_pipe 0 0.00 Total pipe s_pass 0 0.00 Total pass s_fetch 51433 4.59 Total fetch s_hdrbytes 1189049759 106098.85 Total header bytes s_bodybytes 5149727833 459509.93 Total body bytes sess_closed 5409469 482.69 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 0 0.00 Session herd shm_records 226158115 20180.08 SHM records shm_writes 21752857 1941.01 SHM writes shm_flushes 0 0.00 SHM flushes due to overflow shm_cont 27172 2.42 SHM MTX contention shm_cycles 97 0.01 SHM cycles through buffer sm_nreq 0 0.00 allocator requests sm_nobj 0 . outstanding allocations sm_balloc 0 . bytes allocated sm_bfree 0 . bytes free sma_nreq 102756 9.17 SMA allocator requests sma_nobj 91120 . SMA outstanding allocations sma_nbytes 72897093 . SMA outstanding bytes sma_balloc 82131133 . SMA bytes allocated sma_bfree 9234040 . SMA bytes free sms_nreq 1 0.00 SMS allocator requests sms_nobj 0 . SMS outstanding allocations sms_nbytes 0 . SMS outstanding bytes sms_balloc 418 . SMS bytes allocated sms_bfree 418 . SMS bytes freed backend_req 51434 4.59 Backend requests made n_vcl 9 0.00 N vcl total n_vcl_avail 9 0.00 N vcl available n_vcl_discard 0 0.00 N vcl discarded n_purge 155 . N total active purges n_purge_add 155 0.01 N new purges added n_purge_retire 0 0.00 N old purges deleted n_purge_obj_test 43087 3.84 N objects tested n_purge_re_test 561069 50.06 N regexps tested against n_purge_dups 140 0.01 N duplicate purges removed hcb_nolock 5409434 482.68 HCB Lookups without lock hcb_lock 45671 4.08 HCB Lookups with lock hcb_insert 45671 4.08 HCB Inserts esi_parse 0 0.00 Objects ESI parsed (unlock) esi_errors 0 0.00 ESI parse errors (unlock) accept_fail 0 0.00 Accept failures client_drop_late 0 0.00 Connection dropped late uptime 11207 1.00 Client uptime backend_retry 0 0.00 Backend conn. retry dir_dns_lookups 0 0.00 DNS director lookups dir_dns_failed 0 0.00 DNS director failed lookups dir_dns_hit 0 0.00 DNS director cached lookups hit dir_dns_cache_full 0 0.00 DNS director full dnscache fetch_1xx 0 0.00 Fetch no body (1xx) fetch_204 0 0.00 Fetch no body (204) fetch_304 0 0.00 Fetch no body (304)
Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858414] python invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858420] python cpuset=/ mems_allowed=0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858424] Pid: 5766, comm: python Not tainted 2.6.32-305-ec2 #9-Ubuntu Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858426] Call Trace: Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858436] [<ffffffff8107c47c>] ? cpuset_print_task_mems_allowed+0x8c/0xc0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858442] [<ffffffff810b0cd3>] oom_kill_process+0xe3/0x210 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858445] [<ffffffff810b0e50>] __out_of_memory+0x50/0xb0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858448] [<ffffffff810b0f0f>] out_of_memory+0x5f/0xc0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858451] [<ffffffff810b3a81>] __alloc_pages_slowpath+0x4c1/0x560 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858455] [<ffffffff810b3c91>] __alloc_pages_nodemask+0x171/0x180 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858458] [<ffffffff810b6c87>] __do_page_cache_readahead+0xd7/0x220 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858461] [<ffffffff810b6dec>] ra_submit+0x1c/0x20 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858464] [<ffffffff810af04e>] filemap_fault+0x3fe/0x450 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858468] [<ffffffff810cb220>] __do_fault+0x50/0x680 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858470] [<ffffffff810cd160>] handle_mm_fault+0x260/0x4f0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858476] [<ffffffff814a5fd7>] do_page_fault+0x147/0x390 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858479] [<ffffffff814a3e18>] page_fault+0x28/0x30 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858481] Mem-Info: Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858483] DMA per-cpu: Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858484] CPU 0: hi: 0, btch: 1 usd: 0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858486] CPU 1: hi: 0, btch: 1 usd: 0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858487] DMA32 per-cpu: Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858489] CPU 0: hi: 155, btch: 38 usd: 146 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858491] CPU 1: hi: 155, btch: 38 usd: 178 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858492] Normal per-cpu: Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858493] CPU 0: hi: 155, btch: 38 usd: 136 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858495] CPU 1: hi: 155, btch: 38 usd: 43 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858499] active_anon:1561108 inactive_anon:312311 isolated_anon:0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858500] active_file:133 inactive_file:251 isolated_file:0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858501] unevictable:0 dirty:9 writeback:0 unstable:0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858501] free:10533 slab_reclaimable:711 slab_unreclaimable:7610 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858503] mapped:104 shmem:46 pagetables:0 bounce:0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858508] DMA free:16384kB min:20kB low:24kB high:28kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:16160kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:0kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858513] lowmem_reserve[]: 0 4024 7559 7559 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858519] DMA32 free:19904kB min:5916kB low:7392kB high:8872kB active_anon:3246376kB inactive_anon:649464kB active_file:0kB inactive_file:448kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:4120800kB mlocked:0kB dirty:4kB writeback:0kB mapped:164kB shmem:16kB slab_reclaimable:212kB slab_unreclaimable:5428kB kernel_stack:112kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:59 all_unreclaimable? yes Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858524] lowmem_reserve[]: 0 0 3534 3534 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858530] Normal free:5844kB min:5196kB low:6492kB high:7792kB active_anon:2998056kB inactive_anon:599780kB active_file:532kB inactive_file:556kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3619728kB mlocked:0kB dirty:32kB writeback:0kB mapped:252kB shmem:168kB slab_reclaimable:2632kB slab_unreclaimable:25012kB kernel_stack:2272kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:672 all_unreclaimable? no Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858534] lowmem_reserve[]: 0 0 0 0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858536] DMA: 0*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 4*4096kB = 16384kB Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858543] DMA32: 2942*4kB 1*8kB 0*16kB 0*32kB 1*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 1*2048kB 1*4096kB = 19904kB Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858549] Normal: 471*4kB 3*8kB 6*16kB 2*32kB 3*64kB 0*128kB 0*256kB 1*512kB 1*1024kB 1*2048kB 0*4096kB = 5844kB Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858555] 477 total pagecache pages Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858557] 0 pages in swap cache Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858559] Swap cache stats: add 0, delete 0, find 0/0 Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858560] Free swap = 0kB Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.858561] Total swap = 0kB Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.882870] 1968128 pages RAM Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.882873] 61087 pages reserved Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.882874] 1106 pages shared Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.882875] 1894560 pages non-shared Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.882878] Out of memory: kill process 1491 (varnishd) score 2838972 or a child Mar 23 00:35:06 ip-10-116-105-253 kernel: [1541993.882892] Killed process 1492 (varnishd) Mar 23 00:35:07 ip-10-116-105-253 varnishd[1491]: Child (1492) died signal=9 Mar 23 00:35:07 ip-10-116-105-253 varnishd[1491]: Child cleanup complete Mar 23 00:35:07 ip-10-116-105-253 varnishd[1491]: child (21675) Started Mar 23 00:35:07 ip-10-116-105-253 varnishd[1491]: Child (21675) said Mar 23 00:35:07 ip-10-116-105-253 varnishd[1491]: Child (21675) said Child starts
_______________________________________________ varnish-misc mailing list [email protected] http://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
