[For Help] Varnish error information
杨尧
yao.yang at autonavi.com
Tue Oct 30 08:04:16 CET 2012
Hi, All,
I used Varnish for half a year, these days some errors puzzled me.
And I find some error informations from /var/log/message file.
Is my fault or the software's bug?
Thanks.
Yangyao
________________________________
Oct 28 03:47:01 kernel: imklog 4.6.2, log source = /proc/kmsg started.
Oct 28 03:47:01 rsyslogd: [origin software="rsyslogd" swVersion="4.6.2" x-pid="1721" x-info="http://www.rsyslog.com"] (re)start
Oct 28 03:47:39 rhsm-complianced: This system is missing one or more valid entitlement certificates. Please run subscription-manager for more information.
Oct 28 20:20:01 kernel: varnishncsa[17385]: segfault at 7f2a06670f58 ip 00007f2a06687005 sp 00007fff242d0720 error 4 in libvarnishapi.so.1.0.0[7f2a0667f000+11000]
Oct 28 20:20:01 abrt[17387]: abrt daemon is not running. If it crashed, /proc/sys/kernel/core_pattern contains a stale value, consider resetting it to 'core'
Oct 29 03:13:03 varnishd[2591]: Child (2592) not responding to CLI, killing it.
Oct 29 03:13:13 varnishd[2591]: Child (2592) not responding to CLI, killing it.
Oct 29 03:13:15 varnishd[2591]: Child (2592) not responding to CLI, killing it.
Oct 29 03:13:15 varnishd[2591]: Child (2592) died signal=3 (core dumped)
Oct 29 03:13:15 varnishd[2591]: child (28563) Started
Oct 29 03:13:15 varnishd[2591]: Child (28563) said Child starts
Oct 29 03:45:46 rhsm-complianced: This system is missing one or more valid entitlement certificates. Please run subscription-manager for more information.
Oct 29 17:23:16 varnishd[2591]: Child (28563) not responding to CLI, killing it.
Oct 29 17:23:26 varnishd[2591]: Child (28563) not responding to CLI, killing it.
Oct 29 17:23:34 varnishd[2591]: Child (28563) not responding to CLI, killing it.
Oct 29 17:23:34 varnishd[2591]: Child (28563) not responding to CLI, killing it.
Oct 29 17:23:34 varnishd[2591]: Child (28563) died signal=3 (core dumped)
Oct 29 17:23:34 varnishd[2591]: child (15919) Started
Oct 29 17:23:34 varnishd[2591]: Child (15919) said Child starts
Oct 29 20:56:39 varnishd[2591]: Child (15919) not responding to CLI, killing it.
Oct 29 20:56:43 varnishd[2591]: Child (15919) not responding to CLI, killing it.
Oct 29 20:56:43 varnishd[2591]: Child (15919) not responding to CLI, killing it.
Oct 29 20:56:43 varnishd[2591]: Child (15919) died signal=3 (core dumped)
Oct 29 20:56:43 varnishd[2591]: child (22868) Started
Oct 29 20:56:43 varnishd[2591]: Child (22868) said Child starts
Oct 30 03:32:46 rhsm-complianced: This system is missing one or more valid entitlement certificates. Please run subscription-manager for more information.
Oct 30 10:30:40 kernel: varnishncsa invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0
Oct 30 10:30:40 kernel: varnishncsa cpuset=/ mems_allowed=0-1
Oct 30 10:30:40 kernel: Pid: 15396, comm: varnishncsa Not tainted 2.6.32-131.0.15.el6.x86_64 #1
Oct 30 10:30:40 kernel: Call Trace:
Oct 30 10:30:40 kernel: [<ffffffff810c0101>] ? cpuset_print_task_mems_allowed+0x91/0xb0
Oct 30 10:30:40 kernel: [<ffffffff811102bb>] ? oom_kill_process+0xcb/0x2e0
Oct 30 10:30:40 kernel: [<ffffffff81110880>] ? select_bad_process+0xd0/0x110
Oct 30 10:30:40 kernel: [<ffffffff81110918>] ? __out_of_memory+0x58/0xc0
Oct 30 10:30:40 kernel: [<ffffffff81110b19>] ? out_of_memory+0x199/0x210
Oct 30 10:30:40 kernel: [<ffffffff811202dd>] ? __alloc_pages_nodemask+0x80d/0x8b0
Oct 30 10:30:40 kernel: [<ffffffff8115464a>] ? alloc_pages_current+0xaa/0x110
Oct 30 10:30:40 kernel: [<ffffffff8110d717>] ? __page_cache_alloc+0x87/0x90
Oct 30 10:30:40 kernel: [<ffffffff81122c4b>] ? __do_page_cache_readahead+0xdb/0x210
Oct 30 10:30:40 kernel: [<ffffffff81122da1>] ? ra_submit+0x21/0x30
Oct 30 10:30:40 kernel: [<ffffffff8110e9e3>] ? filemap_fault+0x4c3/0x500
Oct 30 10:30:40 kernel: [<ffffffff812628a9>] ? cpumask_next_and+0x29/0x50
Oct 30 10:30:40 kernel: [<ffffffff81137114>] ? __do_fault+0x54/0x510
Oct 30 10:30:40 kernel: [<ffffffff811376c7>] ? handle_pte_fault+0xf7/0xb50
Oct 30 10:30:40 kernel: [<ffffffff8100987e>] ? __switch_to+0x26e/0x320
Oct 30 10:30:40 kernel: [<ffffffff81057f99>] ? find_busiest_queue+0x69/0x150
Oct 30 10:30:40 kernel: [<ffffffff811382f8>] ? handle_mm_fault+0x1d8/0x2a0
Oct 30 10:30:40 kernel: [<ffffffff81092ff3>] ? __hrtimer_start_range_ns+0x1a3/0x460
Oct 30 10:30:40 kernel: [<ffffffff81041529>] ? __do_page_fault+0x139/0x480
Oct 30 10:30:40 kernel: [<ffffffff8109332f>] ? hrtimer_try_to_cancel+0x3f/0xd0
Oct 30 10:30:40 kernel: [<ffffffff810933e2>] ? hrtimer_cancel+0x22/0x30
Oct 30 10:30:40 kernel: [<ffffffff814dccc3>] ? do_nanosleep+0x93/0xc0
Oct 30 10:30:40 kernel: [<ffffffff810934b4>] ? hrtimer_nanosleep+0xc4/0x180
Oct 30 10:30:40 kernel: [<ffffffff810922a0>] ? hrtimer_wakeup+0x0/0x30
Oct 30 10:30:40 kernel: [<ffffffff814e0c3e>] ? do_page_fault+0x3e/0xa0
Oct 30 10:30:40 kernel: [<ffffffff814ddfe5>] ? page_fault+0x25/0x30
Oct 30 10:30:40 kernel: Mem-Info:
Oct 30 10:30:40 kernel: Node 0 DMA per-cpu:
Oct 30 10:30:40 kernel: CPU 0: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 1: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 2: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 3: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 4: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 5: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 6: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 7: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 8: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 9: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 10: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 11: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 12: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 13: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 14: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: CPU 15: hi: 0, btch: 1 usd: 0
Oct 30 10:30:40 kernel: Node 0 DMA32 per-cpu:
Oct 30 10:30:40 kernel: CPU 0: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 1: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 2: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 3: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 4: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 5: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 6: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 7: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 8: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 9: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 10: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 11: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 12: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 13: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 14: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 15: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: Node 0 Normal per-cpu:
Oct 30 10:30:40 kernel: CPU 0: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 1: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 2: hi: 186, btch: 31 usd: 11
Oct 30 10:30:40 kernel: CPU 3: hi: 186, btch: 31 usd: 2
Oct 30 10:30:40 kernel: CPU 4: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 5: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 6: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 7: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 8: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 9: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 10: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 11: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 12: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 13: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 14: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 15: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: Node 1 Normal per-cpu:
Oct 30 10:30:40 kernel: CPU 0: hi: 186, btch: 31 usd: 5
Oct 30 10:30:40 kernel: CPU 1: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 2: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 3: hi: 186, btch: 31 usd: 1
Oct 30 10:30:40 kernel: CPU 4: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 5: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 6: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 7: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 8: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 9: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 10: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 11: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 12: hi: 186, btch: 31 usd: 8
Oct 30 10:30:40 kernel: CPU 13: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 14: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: CPU 15: hi: 186, btch: 31 usd: 0
Oct 30 10:30:40 kernel: active_anon:15180189 inactive_anon:868880 isolated_anon:0
Oct 30 10:30:40 kernel: active_file:496 inactive_file:603 isolated_file:0
Oct 30 10:30:40 kernel: unevictable:0 dirty:22 writeback:20 unstable:0
Oct 30 10:30:40 kernel: free:55664 slab_reclaimable:10223 slab_unreclaimable:284822
Oct 30 10:30:40 kernel: mapped:386 shmem:0 pagetables:54263 bounce:0
Oct 30 10:30:40 kernel: Node 0 DMA free:15616kB 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:15224kB 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? no
Oct 30 10:30:40 kernel: lowmem_reserve[]: 0 2991 32281 32281
Oct 30 10:30:40 kernel: Node 0 DMA32 free:121196kB min:4168kB low:5208kB high:6252kB active_anon:1856648kB inactive_anon:457828kB active_file:124kB inactive_file:372kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:3063392kB mlocked:0kB dirty:12kB writeback:16kB mapped:156kB shmem:0kB slab_reclaimable:3732kB slab_unreclaimable:2508kB kernel_stack:0kB pagetables:5060kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:352 all_unreclaimable? no
Oct 30 10:30:40 kernel: lowmem_reserve[]: 0 0 29290 29290
Oct 30 10:30:40 kernel: Node 0 Normal free:40808kB min:40844kB low:51052kB high:61264kB active_anon:27839988kB inactive_anon:1739808kB active_file:1104kB inactive_file:1240kB unevictable:0kB isolated(anon):128kB isolated(file):0kB present:29992960kB mlocked:0kB dirty:52kB writeback:40kB mapped:332kB shmem:0kB slab_reclaimable:19552kB slab_unreclaimable:584592kB kernel_stack:10656kB pagetables:107120kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:1528 all_unreclaimable? no
Oct 30 10:30:40 kernel: lowmem_reserve[]: 0 0 0 0
Oct 30 10:30:40 kernel: Node 1 Normal free:45036kB min:45072kB low:56340kB high:67608kB active_anon:31024120kB inactive_anon:1277884kB active_file:756kB inactive_file:800kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:33095680kB mlocked:0kB dirty:24kB writeback:24kB mapped:1056kB shmem:0kB slab_reclaimable:17608kB slab_unreclaimable:552188kB kernel_stack:5456kB pagetables:104872kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:1267 all_unreclaimable? no
Oct 30 10:30:40 kernel: lowmem_reserve[]: 0 0 0 0
Oct 30 10:30:40 kernel: Node 0 DMA: 2*4kB 1*8kB 1*16kB 1*32kB 1*64kB 1*128kB 0*256kB 0*512kB 1*1024kB 1*2048kB 3*4096kB = 15616kB
Oct 30 10:30:40 kernel: Node 0 DMA32: 1357*4kB 979*8kB 689*16kB 1413*32kB 447*64kB 66*128kB 15*256kB 10*512kB 7*1024kB 0*2048kB 0*4096kB = 122684kB
Oct 30 10:30:40 kernel: Node 0 Normal: 10120*4kB 45*8kB 7*16kB 3*32kB 1*64kB 1*128kB 0*256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB = 42776kB
Oct 30 10:30:40 kernel: Node 1 Normal: 2241*4kB 1460*8kB 766*16kB 273*32kB 51*64kB 2*128kB 0*256kB 1*512kB 1*1024kB 0*2048kB 0*4096kB = 46692kB
Oct 30 10:30:40 kernel: 10994 total pagecache pages
Oct 30 10:30:40 kernel: 9447 pages in swap cache
Oct 30 10:30:40 kernel: Swap cache stats: add 10177329, delete 10167882, find 6787957/7512667
Oct 30 10:30:40 kernel: Free swap = 0kB
Oct 30 10:30:40 kernel: Total swap = 4194296kB
Oct 30 10:30:40 kernel: 16777215 pages RAM
Oct 30 10:30:40 kernel: 285063 pages reserved
Oct 30 10:30:40 kernel: 2192 pages shared
Oct 30 10:30:40 kernel: 16161719 pages non-shared
Oct 30 10:30:40 kernel: Out of memory: kill process 2591 (varnishd) score 164119553 or a child
Oct 30 10:30:40 kernel: Killed process 22868 (varnishd) vsz:147678356kB, anon-rss:63571052kB, file-rss:616kB
Oct 30 10:30:50 varnishd[2591]: Child (22868) not responding to CLI, killing it.
Oct 30 10:30:53 varnishd[2591]: Child (22868) not responding to CLI, killing it.
Oct 30 10:30:53 varnishd[2591]: Child (22868) died signal=9
Oct 30 10:30:53 varnishd[2591]: child (15405) Started
Oct 30 10:30:53 varnishd[2591]: Child (15405) said Child starts
Oct 30 14:44:27 varnishd[21828]: Platform: Linux,2.6.32-131.0.15.el6.x86_64,x86_64,-smalloc,-smalloc,-hcritbit
Oct 30 14:44:27 varnishd[21828]: Child start failed: could not open sockets
Oct 30 14:44:32 varnishd[21855]: Platform: Linux,2.6.32-131.0.15.el6.x86_64,x86_64,-smalloc,-smalloc,-hcritbit
Oct 30 14:44:32 varnishd[21855]: child (21856) Started
Oct 30 14:44:32 varnishd[21855]: Child (21856) said Child starts
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20121030/7ffde25f/attachment-0001.html>
More information about the varnish-misc
mailing list