Varnish Error Message
杨尧
yao.yang at autonavi.com
Thu Jan 24 03:37:46 CET 2013
Hi all，
My Varnish was reset by itself this morning，the following is the message in /var/log/message file log.
And my Varnish boot parameters is:
./varnishd -f /opt/varnish/etc/varnish/default.vcl -s malloc,40G -T 127.0.0.1:2000 -a 0.0.0.0:80
\ -p thread_pool_max=4000
\ -p thread_pools=14
\ -p thread_pool_min=40
\ -p thread_pool_add_delay=2
\ -p session_linger=50
\ -p sess_workspace=5000000
The Resarting of Varnish affects the hitrate, and how to avoild this to happen again? I think the reason which may be the size of memory is not suitable.
[cid:_Foxmail.0 at 191AF9D2-9CFE-4FD9-9CA7-D80F89C34264]
[cid:_Foxmail.1 at 0E1CC645-2BBA-44B2-AA32-E37FDA325F78]
________________________________
Jan 24 09:33:06 kernel: varnishd invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0, oom_score_adj=0
Jan 24 09:33:06 kernel: varnishd cpuset=/ mems_allowed=0-1
Jan 24 09:33:06 kernel: Pid: 13655, comm: varnishd Not tainted 2.6.32-220.el6.x86_64 #1
Jan 24 09:33:06 kernel: Call Trace:
Jan 24 09:33:06 kernel: [<ffffffff810c2cb1>] ? cpuset_print_task_mems_allowed+0x91/0xb0
Jan 24 09:33:06 kernel: [<ffffffff81113a30>] ? dump_header+0x90/0x1b0
Jan 24 09:33:06 kernel: [<ffffffff810e11fe>] ? __delayacct_freepages_end+0x2e/0x30
Jan 24 09:33:06 kernel: [<ffffffff8120d97c>] ? security_real_capable_noaudit+0x3c/0x70
Jan 24 09:33:06 kernel: [<ffffffff81113eba>] ? oom_kill_process+0x8a/0x2c0
Jan 24 09:33:06 kernel: [<ffffffff81113df1>] ? select_bad_process+0xe1/0x120
Jan 24 09:33:06 kernel: [<ffffffff81114310>] ? out_of_memory+0x220/0x3c0
Jan 24 09:33:06 kernel: [<ffffffff8112402e>] ? __alloc_pages_nodemask+0x89e/0x940
Jan 24 09:33:06 kernel: [<ffffffff81158b7a>] ? alloc_pages_current+0xaa/0x110
Jan 24 09:33:06 kernel: [<ffffffff81110e57>] ? __page_cache_alloc+0x87/0x90
Jan 24 09:33:06 kernel: [<ffffffff81126a7b>] ? __do_page_cache_readahead+0xdb/0x210
Jan 24 09:33:06 kernel: [<ffffffff81126bd1>] ? ra_submit+0x21/0x30
Jan 24 09:33:06 kernel: [<ffffffff81112123>] ? filemap_fault+0x4c3/0x500
Jan 24 09:33:06 kernel: [<ffffffff8113b2c4>] ? __do_fault+0x54/0x510
Jan 24 09:33:06 kernel: [<ffffffff8113b877>] ? handle_pte_fault+0xf7/0xb50
Jan 24 09:33:06 kernel: [<ffffffff8141bf31>] ? sock_aio_read+0x181/0x190
Jan 24 09:33:06 kernel: [<ffffffff8117619b>] ? do_sync_readv_writev+0xfb/0x140
Jan 24 09:33:06 kernel: [<ffffffff8113c4b4>] ? handle_mm_fault+0x1e4/0x2b0
Jan 24 09:33:06 kernel: [<ffffffff8117641a>] ? do_sync_read+0xfa/0x140
Jan 24 09:33:06 kernel: [<ffffffff81042b39>] ? __do_page_fault+0x139/0x480
Jan 24 09:33:06 kernel: [<ffffffff8141cdec>] ? lock_sock_nested+0xac/0xc0
Jan 24 09:33:06 kernel: [<ffffffff814ef4fb>] ? _spin_unlock_bh+0x1b/0x20
Jan 24 09:33:06 kernel: [<ffffffff8141cd2e>] ? release_sock+0xce/0xe0
Jan 24 09:33:06 kernel: [<ffffffff8141ecad>] ? sock_setsockopt+0x16d/0x6f0
Jan 24 09:33:06 kernel: [<ffffffff814f246e>] ? do_page_fault+0x3e/0xa0
Jan 24 09:33:06 kernel: [<ffffffff814ef825>] ? page_fault+0x25/0x30
Jan 24 09:33:06 kernel: Mem-Info:
Jan 24 09:33:06 kernel: Node 0 DMA per-cpu:
Jan 24 09:33:06 kernel: CPU 0: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 1: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 2: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 3: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 4: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 5: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 6: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 7: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 8: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 9: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 10: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 11: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 12: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 13: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 14: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: CPU 15: hi: 0, btch: 1 usd: 0
Jan 24 09:33:06 kernel: Node 0 DMA32 per-cpu:
Jan 24 09:33:06 kernel: CPU 0: hi: 186, btch: 31 usd: 68
Jan 24 09:33:06 kernel: CPU 1: hi: 186, btch: 31 usd: 36
Jan 24 09:33:06 kernel: CPU 2: hi: 186, btch: 31 usd: 139
Jan 24 09:33:06 kernel: CPU 3: hi: 186, btch: 31 usd: 37
Jan 24 09:33:06 kernel: CPU 4: hi: 186, btch: 31 usd: 115
Jan 24 09:33:06 kernel: CPU 5: hi: 186, btch: 31 usd: 17
Jan 24 09:33:06 kernel: CPU 6: hi: 186, btch: 31 usd: 82
Jan 24 09:33:06 kernel: CPU 7: hi: 186, btch: 31 usd: 32
Jan 24 09:33:06 kernel: CPU 8: hi: 186, btch: 31 usd: 18
Jan 24 09:33:06 kernel: CPU 9: hi: 186, btch: 31 usd: 26
Jan 24 09:33:06 kernel: CPU 10: hi: 186, btch: 31 usd: 150
Jan 24 09:33:06 kernel: CPU 11: hi: 186, btch: 31 usd: 49
Jan 24 09:33:06 kernel: CPU 12: hi: 186, btch: 31 usd: 115
Jan 24 09:33:06 kernel: CPU 13: hi: 186, btch: 31 usd: 55
Jan 24 09:33:06 kernel: CPU 14: hi: 186, btch: 31 usd: 70
Jan 24 09:33:06 kernel: CPU 15: hi: 186, btch: 31 usd: 0
Jan 24 09:33:06 kernel: Node 0 Normal per-cpu:
Jan 24 09:33:06 kernel: CPU 0: hi: 186, btch: 31 usd: 169
Jan 24 09:33:06 kernel: CPU 1: hi: 186, btch: 31 usd: 29
Jan 24 09:33:06 kernel: CPU 2: hi: 186, btch: 31 usd: 91
Jan 24 09:33:06 kernel: CPU 3: hi: 186, btch: 31 usd: 42
Jan 24 09:33:06 kernel: CPU 4: hi: 186, btch: 31 usd: 121
Jan 24 09:33:06 kernel: CPU 5: hi: 186, btch: 31 usd: 47
Jan 24 09:33:06 kernel: CPU 6: hi: 186, btch: 31 usd: 93
Jan 24 09:33:06 kernel: CPU 7: hi: 186, btch: 31 usd: 38
Jan 24 09:33:06 kernel: CPU 8: hi: 186, btch: 31 usd: 43
Jan 24 09:33:06 kernel: CPU 9: hi: 186, btch: 31 usd: 26
Jan 24 09:33:06 kernel: CPU 10: hi: 186, btch: 31 usd: 139
Jan 24 09:33:06 kernel: CPU 11: hi: 186, btch: 31 usd: 0
Jan 24 09:33:06 kernel: CPU 12: hi: 186, btch: 31 usd: 96
Jan 24 09:33:06 kernel: CPU 13: hi: 186, btch: 31 usd: 1
Jan 24 09:33:06 kernel: CPU 14: hi: 186, btch: 31 usd: 79
Jan 24 09:33:06 kernel: CPU 15: hi: 186, btch: 31 usd: 0
Jan 24 09:33:06 kernel: Node 1 Normal per-cpu:
Jan 24 09:33:06 kernel: CPU 0: hi: 186, btch: 31 usd: 35
Jan 24 09:33:06 kernel: CPU 1: hi: 186, btch: 31 usd: 26
Jan 24 09:33:06 kernel: CPU 2: hi: 186, btch: 31 usd: 84
Jan 24 09:33:06 kernel: CPU 3: hi: 186, btch: 31 usd: 38
Jan 24 09:33:06 kernel: CPU 4: hi: 186, btch: 31 usd: 116
Jan 24 09:33:06 kernel: CPU 5: hi: 186, btch: 31 usd: 24
Jan 24 09:33:06 kernel: CPU 6: hi: 186, btch: 31 usd: 112
Jan 24 09:33:06 kernel: CPU 7: hi: 186, btch: 31 usd: 36
Jan 24 09:33:06 kernel: CPU 8: hi: 186, btch: 31 usd: 70
Jan 24 09:33:06 kernel: CPU 9: hi: 186, btch: 31 usd: 96
Jan 24 09:33:06 kernel: CPU 10: hi: 186, btch: 31 usd: 178
Jan 24 09:33:06 kernel: CPU 11: hi: 186, btch: 31 usd: 53
Jan 24 09:33:06 kernel: CPU 12: hi: 186, btch: 31 usd: 111
Jan 24 09:33:06 kernel: CPU 13: hi: 186, btch: 31 usd: 29
Jan 24 09:33:06 kernel: CPU 14: hi: 186, btch: 31 usd: 88
Jan 24 09:33:06 kernel: CPU 15: hi: 186, btch: 31 usd: 0
Jan 24 09:33:06 kernel: active_anon:11312555 inactive_anon:800769 isolated_anon:0
Jan 24 09:33:06 kernel: active_file:390 inactive_file:2546 isolated_file:0
Jan 24 09:33:06 kernel: unevictable:0 dirty:234 writeback:9 unstable:0
Jan 24 09:33:06 kernel: free:46381 slab_reclaimable:4695 slab_unreclaimable:19412
Jan 24 09:33:06 kernel: mapped:865 shmem:1 pagetables:27687 bounce:0
Jan 24 09:33:06 kernel: Node 0 DMA free:15740kB min:24kB low:28kB high:36kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15356kB 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
Jan 24 09:33:06 kernel: lowmem_reserve[]: 0 3502 24207 24207
Jan 24 09:33:06 kernel: Node 0 DMA32 free:89316kB min:6512kB low:8140kB high:9768kB active_anon:2469592kB inactive_anon:492884kB active_file:68kB inactive_file:1768kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3586464kB mlocked:0kB dirty:60kB writeback:16kB mapped:52kB shmem:0kB slab_reclaimable:4092kB slab_unreclaimable:9460kB kernel_stack:16kB pagetables:4960kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:128 all_unreclaimable? yes
Jan 24 09:33:06 kernel: lowmem_reserve[]: 0 0 20705 20705
Jan 24 09:33:06 kernel: Node 0 Normal free:37136kB min:38496kB low:48120kB high:57744kB active_anon:19667276kB inactive_anon:1405088kB active_file:132kB inactive_file:1008kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:21201920kB mlocked:0kB dirty:320kB writeback:20kB mapped:188kB shmem:4kB slab_reclaimable:9180kB slab_unreclaimable:41676kB kernel_stack:5696kB pagetables:61332kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:71 all_unreclaimable? yes
Jan 24 09:33:06 kernel: lowmem_reserve[]: 0 0 0 0
Jan 24 09:33:06 kernel: Node 1 Normal free:43332kB min:45072kB low:56340kB high:67608kB active_anon:23113352kB inactive_anon:1305104kB active_file:1360kB inactive_file:7408kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:24821756kB mlocked:0kB dirty:556kB writeback:0kB mapped:3220kB shmem:0kB slab_reclaimable:5508kB slab_unreclaimable:26512kB kernel_stack:3888kB pagetables:44456kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:42944 all_unreclaimable? yes
Jan 24 09:33:06 kernel: lowmem_reserve[]: 0 0 0 0
Jan 24 09:33:06 kernel: Node 0 DMA: 3*4kB 2*8kB 2*16kB 2*32kB 2*64kB 1*128kB 0*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15740kB
Jan 24 09:33:06 kernel: Node 0 DMA32: 681*4kB 876*8kB 752*16kB 565*32kB 233*64kB 150*128kB 56*256kB 0*512kB 1*1024kB 0*2048kB 0*4096kB = 89316kB
Jan 24 09:33:06 kernel: Node 0 Normal: 682*4kB 661*8kB 264*16kB 144*32kB 89*64kB 50*128kB 22*256kB 3*512kB 1*1024kB 0*2048kB 0*4096kB = 37136kB
Jan 24 09:33:06 kernel: Node 1 Normal: 762*4kB 638*8kB 577*16kB 347*32kB 122*64kB 16*128kB 1*256kB 1*512kB 4*1024kB 0*2048kB 0*4096kB = 43208kB
Jan 24 09:33:06 kernel: 6158 total pagecache pages
Jan 24 09:33:06 kernel: 3086 pages in swap cache
Jan 24 09:33:06 kernel: Swap cache stats: add 4892481, delete 4889395, find 4972726/5258977
Jan 24 09:33:06 kernel: Free swap = 0kB
Jan 24 09:33:06 kernel: Total swap = 4194296kB
Jan 24 09:33:06 kernel: 12582910 pages RAM
Jan 24 09:33:06 kernel: 229730 pages reserved
Jan 24 09:33:06 kernel: 5799 pages shared
Jan 24 09:33:06 kernel: 12293308 pages non-shared
Jan 24 09:33:06 kernel: [ pid ] uid tgid total_vm rss cpu oom_adj oom_score_adj name
Jan 24 09:33:06 kernel: [ 654] 0 654 2708 0 0 -17 -1000 udevd
Jan 24 09:33:06 kernel: [ 1810] 0 1810 62714 71 0 0 0 rsyslogd
Jan 24 09:33:06 kernel: [ 1855] 0 1855 1031 30 1 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1864] 0 1864 1031 30 2 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1865] 0 1865 2301 38 1 0 0 irqbalance
Jan 24 09:33:06 kernel: [ 1874] 0 1874 1031 30 3 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1875] 0 1875 1031 30 3 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1878] 0 1878 1031 30 7 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1880] 0 1880 1031 30 7 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1883] 0 1883 1031 30 4 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1884] 0 1884 1031 30 6 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1892] 0 1892 1031 30 8 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1910] 0 1910 1031 30 12 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1912] 0 1912 1031 30 3 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1913] 0 1913 1031 31 2 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1914] 0 1914 1031 30 12 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1916] 0 1916 1031 30 14 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1917] 0 1917 1031 30 2 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1918] 0 1918 1031 30 10 0 0 cpuspeed
Jan 24 09:33:06 kernel: [ 1919] 0 1919 6859 1 10 0 0 rpc.idmapd
Jan 24 09:33:06 kernel: [ 5615] 81 5615 5397 55 4 0 0 dbus-daemon
Jan 24 09:33:06 kernel: [ 5626] 0 5626 47285 2 3 0 0 cupsd
Jan 24 09:33:06 kernel: [ 5653] 0 5653 1033 0 9 0 0 acpid
Jan 24 09:33:06 kernel: [ 5662] 68 5662 6339 167 1 0 0 hald
Jan 24 09:33:06 kernel: [ 5663] 0 5663 4539 1 1 0 0 hald-runner
Jan 24 09:33:06 kernel: [ 5692] 0 5692 5068 1 8 0 0 hald-addon-inpu
Jan 24 09:33:06 kernel: [ 5706] 68 5706 4464 1 1 0 0 hald-addon-acpi
Jan 24 09:33:06 kernel: [ 5725] 0 5725 113079 36 1 0 0 automount
Jan 24 09:33:06 kernel: [ 5742] 0 5742 49251 166 9 0 0 snmpd
Jan 24 09:33:06 kernel: [ 5790] 0 5790 29709 1 0 0 0 abrtd
Jan 24 09:33:06 kernel: [ 5798] 0 5798 2304 19 0 0 0 abrt-dump-oops
Jan 24 09:33:06 kernel: [ 5809] 496 5809 348349 267 1 0 0 qpidd
Jan 24 09:33:06 kernel: [ 5856] 0 5856 29320 78 0 0 0 crond
Jan 24 09:33:06 kernel: [ 5867] 0 5867 5373 4 1 0 0 atd
Jan 24 09:33:06 kernel: [ 5927] 0 5927 16004 24 2 0 0 sshd
Jan 24 09:33:06 kernel: [ 6296] 0 6296 43628 16 0 0 0 hpsmhd
Jan 24 09:33:06 kernel: [ 6298] 0 6298 7732 1 0 0 0 rotatelogs
Jan 24 09:33:06 kernel: [ 6299] 0 6299 7732 1 15 0 0 rotatelogs
Jan 24 09:33:06 kernel: [ 6301] 501 6301 43628 11 0 0 0 hpsmhd
Jan 24 09:33:06 kernel: [ 6302] 501 6302 43628 3 12 0 0 hpsmhd
Jan 24 09:33:06 kernel: [ 6303] 501 6303 43628 3 13 0 0 hpsmhd
Jan 24 09:33:06 kernel: [ 6304] 501 6304 43628 3 14 0 0 hpsmhd
Jan 24 09:33:06 kernel: [ 6305] 501 6305 43628 3 11 0 0 hpsmhd
Jan 24 09:33:06 kernel: [ 6315] 0 6315 1015 1 3 0 0 mingetty
Jan 24 09:33:06 kernel: [ 6317] 0 6317 1015 1 11 0 0 mingetty
Jan 24 09:33:06 kernel: [ 6319] 0 6319 1015 2 15 0 0 mingetty
Jan 24 09:33:06 kernel: [ 6321] 0 6321 1015 1 2 0 0 mingetty
Jan 24 09:33:06 kernel: [ 6323] 0 6323 2707 0 2 -17 -1000 udevd
Jan 24 09:33:06 kernel: [ 6324] 0 6324 2707 0 4 -17 -1000 udevd
Jan 24 09:33:06 kernel: [ 6325] 0 6325 1015 1 1 0 0 mingetty
Jan 24 09:33:06 kernel: [ 6327] 0 6327 1015 1 10 0 0 mingetty
Jan 24 09:33:06 kernel: [23214] 0 23214 24355 676 8 0 0 varnishncsa
Jan 24 09:33:06 kernel: [23215] 0 23215 1029 35 14 0 0 cronolog
Jan 24 09:33:06 kernel: [27346] 0 27346 35250 693 1 0 0 munin-node
Jan 24 09:33:06 kernel: [12832] 0 12832 5301081 676327 0 0 0 java
Jan 24 09:33:06 kernel: [13112] 0 13112 28072 56 8 0 0 varnishd
Jan 24 09:33:06 kernel: [13113] 99 13113 15328552 11431890 2 0 0 varnishd
Jan 24 09:33:06 kernel: [29597] 0 29597 35034 139 1 0 0 crond
Jan 24 09:33:06 kernel: [29598] 0 29598 35250 939 0 0 0 munin-node
Jan 24 09:33:06 kernel: [29599] 0 29599 2307 147 0 0 0 sh
Jan 24 09:33:06 kernel: [29601] 0 29601 1551 116 0 0 0 tsar
Jan 24 09:33:06 kernel: [29602] 0 29602 35834 985 13 0 0 munin-node
Jan 24 09:33:06 kernel: [29603] 0 29603 2307 187 0 0 0 sh
Jan 24 09:33:06 kernel: [29604] 0 29604 1164 55 9 0 0 ls
Jan 24 09:33:06 kernel: Out of memory: Kill process 13113 (varnishd) score 906 or sacrifice child
Jan 24 09:33:06 kernel: Killed process 13113, UID 99, (varnishd) total-vm:61314208kB, anon-rss:45725988kB, file-rss:1572kB
Jan 24 09:33:11 varnishd[13112]: Child (13113) not responding to CLI, killing it.
Jan 24 09:33:11 varnishd[13112]: Child (13113) not responding to CLI, killing it.
Jan 24 09:33:11 varnishd[13112]: Child (13113) died signal=9
Jan 24 09:33:11 varnishd[13112]: child (29620) Started
Jan 24 09:33:11 varnishd[13112]: Child (29620) said Child starts
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20130124/97d4bf83/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: Catch.jpg
Type: image/jpeg
Size: 93930 bytes
Desc: Catch.jpg
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20130124/97d4bf83/attachment-0002.jpg>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: Catch6F31.jpg
Type: image/jpeg
Size: 123268 bytes
Desc: Catch6F31.jpg
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20130124/97d4bf83/attachment-0003.jpg>
More information about the varnish-misc
mailing list