# Packetbeat HighCPU monitoring memcache

**URL:** https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811
**Category:** Beats
**Tags:** packetbeat
**Created:** [May 23, 2017, 1:00pm UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811 "2017-05-23T13:00:21Z")
**Posts on this page:** 9
**Page:** 1

<div class="post-metadata">

### Author: ![tarp](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/tarp/32/51884_2.png) [@tarp](https://discuss.elastic.co/u/tarp)
#### Post date: [May 23, 2017, 1:00pm UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811/1 "2017-05-23T13:00:21Z")

</div>

Hi,  
I have been monitoring our memcached servers with packetbeat. This was noticed after deploying packetbeat 5.4.0, it may have been happening before, but I'm not 100% sure. I will consistently get packetbeat taking all of the cpu on the server. This impacts the performance of memcache. For now, we have shutoff packetbeat.

I have 4 instances of memcache running on the server. Top looks like this before packetbeat.  
 ![](https://us1.discourse-cdn.com/elastic/original/3X/7/b/7b33602244b48262ebbb3c24d04c6cc6f2a88a0e.png)top - 07:51:32 up 100 days, 6:35, 1 user, load average: 0.19, 0.13, 0.05  
Tasks: 164 total, 1 running, 163 sleeping, 0 stopped, 0 zombie  
Cpu(s): 0.9%us, 3.5%sy, 0.0%ni, 94.3%id, 0.1%wa, 0.0%hi, 1.1%si, 0.0%st  
Mem: 8054356k total, 7672104k used, 382252k free, 65656k buffers  
Swap: 8388604k total, 20220k used, 8368384k free, 4616300k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND  
20020 memcache 20 0 1069m 778m 712 S 6.3 9.9 1832:06 memcached  
20052 memcache 20 0 1067m 783m 712 S 6.0 10.0 1839:16 memcached  
6470 memcache 20 0 558m 190m 708 S 3.3 2.4 2187:18 memcached  
13 root 20 0 0 0 0 S 0.3 0.0 29:47.84 ksoftirqd/2  
1419 root 20 0 63608 3716 3300 S 0.3 0.0 130:39.73 vmtoolsd  
6964 root 20 0 366m 8524 5308 S 0.3 0.1 11:39.54 pxp-agent

Starting up packetbeat it now looks like this.  
 ![](https://us1.discourse-cdn.com/elastic/original/3X/8/c/8c8af88e0617371ac5ea362df4c462b1ef835055.png)top - 07:52:45 up 100 days, 6:36, 1 user, load average: 0.32, 0.19, 0.08  
Tasks: 166 total, 1 running, 165 sleeping, 0 stopped, 0 zombie  
Cpu(s): 24.3%us, 4.9%sy, 0.0%ni, 68.7%id, 0.1%wa, 0.0%hi, 2.0%si, 0.0%st  
Mem: 8054356k total, 7778452k used, 275904k free, 65912k buffers  
Swap: 8388604k total, 20220k used, 8368384k free, 4616040k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND  
20913 root 20 0 457m 110m 10m S 77.1 1.4 0:37.20 packetbeat  
20020 memcache 20 0 1069m 778m 712 S 9.6 9.9 1832:12 memcached  
20052 memcache 20 0 1067m 783m 712 S 7.3 10.0 1839:21 memcached  
6470 memcache 20 0 558m 190m 708 S 1.0 2.4 2187:20 memcached  
52568 root 20 0 4374m 144m 15m S 0.3 1.8 169:59.43 java  
1 root 20 0 30424 1704 1424 S 0.0 0.0 0:09.85 init

The packetbeat.yml is configured like this.

packetbeat.interfaces.device: any  
packetbeat.flows:  
timeout: 30s  
period: 30s  
packetbeat.protocols.memcache:  
ports: [11215, 11216, 11217, 11223]

output.elasticsearch:  
hosts: ['[ingest-logcentral.dx.deere.com:9200](http://ingest-logcentral.dx.deere.com:9200)']

---

<div class="post-metadata">

### Author: ![tarp](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/tarp/32/51884_2.png) [@tarp](https://discuss.elastic.co/u/tarp)
#### Post date: [May 23, 2017, 1:03pm UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811/2 "2017-05-23T13:03:49Z")

</div>

packetbeat log part 1  
2017-05-23T07:51:51-05:00 INFO Home path: [/usr/share/packetbeat] Config path: [/etc/packetbeat] Data path: [/var/lib/packetbeat] Logs path: [/var/log/packetbeat]  
2017-05-23T07:51:51-05:00 INFO Setup Beat: packetbeat; Version: 5.4.0  
2017-05-23T07:51:51-05:00 INFO Loading template enabled. Reading template file: /etc/packetbeat/packetbeat.template.json  
2017-05-23T07:51:51-05:00 INFO Loading template enabled for Elasticsearch 2.x. Reading template file: /etc/packetbeat/packetbeat.template-es2x.json  
2017-05-23T07:51:51-05:00 INFO Loading template enabled for Elasticsearch 6.x. Reading template file: /etc/packetbeat/packetbeat.template-es6x.json  
2017-05-23T07:51:51-05:00 INFO Elasticsearch url: [http://ingest-logcentral.dx.deere.com:9200](http://ingest-logcentral.dx.deere.com:9200)  
2017-05-23T07:51:51-05:00 INFO Activated elasticsearch as output plugin.  
2017-05-23T07:51:51-05:00 INFO Publisher name: ldpn90mc1  
2017-05-23T07:51:51-05:00 INFO Flush Interval set to: 1s  
2017-05-23T07:51:51-05:00 INFO Max Bulk Size set to: 50  
2017-05-23T07:51:51-05:00 INFO Process matching disabled  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: mysql  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: nfs  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: pgsql  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: redis  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: thrift  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: cassandra  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: memcache  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: http  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: mongodb  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: amqp  
2017-05-23T07:51:51-05:00 INFO registered protocol plugin: dns  
2017-05-23T07:51:51-05:00 INFO packetbeat start running.  
2017-05-23T07:51:51-05:00 INFO Connected to Elasticsearch version 5.4.0  
2017-05-23T07:51:51-05:00 INFO Trying to load template for client: [http://ingest-logcentral.dx.deere.com:9200](http://ingest-logcentral.dx.deere.com:9200)  
2017-05-23T07:51:51-05:00 INFO Template already exists and will not be overwritten.  
2017-05-23T07:52:05-05:00 WARN Missing response for non-quiet request  
2017-05-23T07:52:18-05:00 WARN Missing response for non-quiet request  
2017-05-23T07:52:21-05:00 INFO Non-zero metrics in the last 30s: libbeat.es.call\_count.PublishEvents=466 libbeat.es.publish.read\_bytes=234003 libbeat.es.publish.write\_bytes=18094722 libbeat.es.published\_and\_acked\_events=22726 libbeat.publisher.messages\_in\_worker\_queues=23826 libbeat.publisher.published\_events=23827 memcache.unfinished\_transactions=4086 memcache.unmatched\_requests=2 memcache.unmatched\_responses=2707 tcp.dropped\_because\_of\_gaps=5112  
2017-05-23T07:52:51-05:00 INFO Non-zero metrics in the last 30s: libbeat.es.call\_count.PublishEvents=513 libbeat.es.publish.read\_bytes=257996 libbeat.es.publish.write\_bytes=17745335 libbeat.es.published\_and\_acked\_events=25093 libbeat.publisher.messages\_in\_worker\_queues=15581 libbeat.publisher.published\_events=25093 memcache.unfinished\_transactions=4785 memcache.unmatched\_responses=2860 tcp.dropped\_because\_of\_gaps=5301

---

<div class="post-metadata">

### Author: ![tarp](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/tarp/32/51884_2.png) [@tarp](https://discuss.elastic.co/u/tarp)
#### Post date: [May 23, 2017, 1:05pm UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811/3 "2017-05-23T13:05:19Z")

</div>

packetbeat log part 2

2017-05-23T07:52:53-05:00 WARN Missing response for non-quiet request  
2017-05-23T07:52:56-05:00 ERR ParseMemcache(TCP) exception. Recovering, but please report this: runtime error: slice bounds out of range.  
2017-05-23T07:52:56-05:00 ERR Stacktrace: goroutine 49 [running]:  
runtime/debug.Stack(0xbcf45d, 0x2b, 0xc42003f5f0)  
/usr/local/go/src/runtime/debug/stack.go:24 +0x79  
[github.com/elastic/beats/libbeat/logp.Recover](http://github.com/elastic/beats/libbeat/logp.Recover)(0xbc388b, 0x1c)  
/go/src/github.com/elastic/beats/libbeat/logp/log.go:145 +0x138  
panic(0xad3d00, 0xc4200100b0)  
/usr/local/go/src/runtime/panic.go:458 +0x243  
[github.com/elastic/beats/libbeat/common/streambuf.(\*Buffer](http://github.com/elastic/beats/libbeat/common/streambuf.(*Buffer)).Collect(0xc424665730, 0xffffffffffffece3, 0xc42003f7c8, 0x1501, 0xc423da4000, 0x1321c86480, 0xc42003f7c0)  
/go/src/github.com/elastic/beats/libbeat/common/streambuf/streambuf.go:335 +0xb0  
[github.com/elastic/beats/packetbeat/protos/memcache.parseDataBinary](http://github.com/elastic/beats/packetbeat/protos/memcache.parseDataBinary)(0xc424665780, 0xc424665730, 0x10, 0xa9fd20, 0xc42003f858)  
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/binary.go:363 +0x67  
[github.com/elastic/beats/packetbeat/protos/memcache.(\*parser](http://github.com/elastic/beats/packetbeat/protos/memcache.(*parser)).dispatch(0xc424665780, 0xc4224c2104, 0xc424665730, 0x95a, 0x11a6300, 0x7ff712409000)  
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/parse.go:102 +0x54  
[github.com/elastic/beats/packetbeat/protos/memcache.(\*parser](http://github.com/elastic/beats/packetbeat/protos/memcache.(*parser)).parse(0xc424665780, 0xc424665730, 0xed0b627a8, 0x1a1fd208, 0x11a4d20, 0xc4224c2130, 0x1, 0x1)  
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/parse.go:78 +0x49  
[github.com/elastic/beats/packetbeat/protos/memcache.(\*stream](http://github.com/elastic/beats/packetbeat/protos/memcache.(*stream)).parse(0xc424665730, 0xed0b627a8, 0xc41a1fd208, 0x11a4d20, 0x1, 0x0, 0xc41fed9ef7)  
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/plugin\_tcp.go:434 +0x52  
[github.com/elastic/beats/packetbeat/protos/memcache.(\*memcache](http://github.com/elastic/beats/packetbeat/protos/memcache.(*memcache)).memcacheParseTCP(0xc4200a3980, 0xc4244c9860, 0xc4235c0300, 0xc4234bcdd8, 0x0, 0xc4244f2001)  
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/plugin\_tcp.go:139 +0x2ae  
[github.com/elastic/beats/packetbeat/protos/memcache.(\*memcache](http://github.com/elastic/beats/packetbeat/protos/memcache.(*memcache)).Parse(0xc4200a3980, 0xc4235c0300, 0xc4234bcdd8, 0xc4200a3900, 0xac2a20, 0xc4244c9860, 0x0, 0x0)  
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/plugin\_tcp.go:90 +0x137  
[github.com/elastic/beats/packetbeat/protos/tcp.(\*TCPStream](http://github.com/elastic/beats/packetbeat/protos/tcp.(*TCPStream)).addPacket(0xc42003fb60, 0xc4235c0300, 0xc42131b2a0)  
/go/src/github.com/elastic/beats/packetbeat/protos/tcp/tcp.go:115 +0x176  
[github.com/elastic/beats/packetbeat/protos/tcp.(\*TCP](http://github.com/elastic/beats/packetbeat/protos/tcp.(*TCP)).Process(0xc4213bf170, 0xc42016f980, 0xc42131b2a0, 0xc4235c0300)  
/go/src/github.com/elastic/beats/packetbeat/protos/tcp/tcp.go:208 +0x3a2  
[github.com/elastic/beats/packetbeat/decoder.(\*Decoder](http://github.com/elastic/beats/packetbeat/decoder.(*Decoder)).onTCP(0xc42131ad00, 0xc4235c0300)  
/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:317 +0xee  
[github.com/elastic/beats/packetbeat/decoder.(\*Decoder](http://github.com/elastic/beats/packetbeat/decoder.(*Decoder)).process(0xc42131ad00, 0xc4235c0300, 0x2c, 0x578, 0x1176700, 0xc42131ad00)  
/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:258 +0x222  
[github.com/elastic/beats/packetbeat/decoder.(\*Decoder](http://github.com/elastic/beats/packetbeat/decoder.(*Decoder)).OnPacket(0xc42131ad00, 0xc42335b844, 0x578, 0x578, 0xc42515ad20)  
/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:164 +0x343  
[github.com/elastic/beats/packetbeat/sniffer.(\*SnifferSetup](http://github.com/elastic/beats/packetbeat/sniffer.(*SnifferSetup)).Run(0xc42016df80, 0xc1f418, 0xc42112e040)  
/go/src/github.com/elastic/beats/packetbeat/sniffer/sniffer.go:381 +0x493  
[github.com/elastic/beats/packetbeat/beater.(\*packetbeat](http://github.com/elastic/beats/packetbeat/beater.(*packetbeat)).Run.func2(0xc42112e040, 0xc4200acb40, 0xc4213f0060)  
/go/src/github.com/elastic/beats/packetbeat/beater/packetbeat.go:155 +0x6a  
created by [github.com/elastic/beats/packetbeat/beater.(\*packetbeat](http://github.com/elastic/beats/packetbeat/beater.(*packetbeat)).Run  
/go/src/github.com/elastic/beats/packetbeat/beater/packetbeat.go:159 +0x1b2

2017-05-23T07:53:10-05:00 INFO Packetbeat send stop signal  
2017-05-23T07:53:10-05:00 INFO Input finish. Processed 619800 packets. Have a nice day!  
2017-05-23T07:53:10-05:00 INFO flows worker loop stopped  
2017-05-23T07:53:10-05:00 INFO Total non-zero values: libbeat.es.call\_count.PublishEvents=1282 libbeat.es.publish.read\_bytes=644829 libbeat.es.publish.write\_bytes=46014178 libbeat.es.published\_and\_acked\_events=62753 libbeat.publisher.messages\_in\_worker\_queues=46682 libbeat.publisher.published\_events=65404 memcache.unfinished\_transactions=10901 memcache.unmatched\_requests=3 memcache.unmatched\_responses=6250 tcp.dropped\_because\_of\_gaps=11566  
2017-05-23T07:53:10-05:00 INFO Uptime: 1m19.569795953s  
2017-05-23T07:53:10-05:00 INFO packetbeat stopped.

---

<div class="post-metadata">

### Author: ![ruflin](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ruflin/32/3116_2.png) [@ruflin](https://discuss.elastic.co/u/ruflin)
#### Post date: [May 26, 2017, 5:51am UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811/4 "2017-05-26T05:51:43Z")

</div>

It you receive a parse memcache exception it would be good to report this on Github as an issue. Please also add the exact memcache version you are using and your setup. If you could provide some pcap files captured from your traffic, that would be even better for debugging.

---

<div class="post-metadata">

### Author: ![tarp](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/tarp/32/51884_2.png) [@tarp](https://discuss.elastic.co/u/tarp)
#### Post date: [May 26, 2017, 12:43pm UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811/5 "2017-05-26T12:43:40Z")

</div>

I will try to create some documentation for the parse errors. Do you think the high cpu utilization is related to this? I didn't have a problem with 5.3 packetbeat.

---

<div class="post-metadata">

### Author: ![ruflin](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ruflin/32/3116_2.png) [@ruflin](https://discuss.elastic.co/u/ruflin)
#### Post date: [May 29, 2017, 1:16pm UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811/6 "2017-05-29T13:16:14Z")

</div>

Could be, lets see as soon as we have all the info together in a Github issue.

---

<div class="post-metadata">

### Author: ![tudor](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/tudor/32/3753_2.png) [@tudor](https://discuss.elastic.co/u/tudor)
#### Post date: [May 30, 2017, 9:34am UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811/7 "2017-05-30T09:34:52Z")

</div>

Note that Packetbeat has to do sniffing and parsing of all Memcache requests/response. If you have a busy memcache instance, Packetbeat is going to have a hard time keeping up with the highly optimized C implementation of memcache, because it also has more work to do.

You have a couple of options:

- Add a `nice` value to Packetbeat, or restrict it's CPU usage with Cgroups, or limit it to a single CPU (`export GOMAXPROC=1`). All this could result in Packetbeat missing parts of the traffic, but sampling should be random enough that you still get value from it.
- Use the Metricbeat module to monitor memcache. This will only give high level metrics, though.
- Consider monitoring via logs on the application side

HTH

---

<div class="post-metadata">

### Author: ![tarp](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/tarp/32/51884_2.png) [@tarp](https://discuss.elastic.co/u/tarp)
#### Post date: [May 30, 2017, 1:55pm UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811/8 "2017-05-30T13:55:25Z")

</div>

Hi Tudor,

That's a good point. What I really want or care about is the response time currently of the Memcache. I don't need to see every single interaction. For app interactions with memcache we are collecting metrics in AppDynamics from the application point of view so we have that covered. What I need to do is create a synthetic transaction and record that time. It may make more sense to look at heartbeat and do something with that instead.

Thanks,  
Tim

---

<div class="post-metadata">

### Author: ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)
#### Post date: [June 27, 2017, 1:55pm UTC](https://discuss.elastic.co/t/packetbeat-highcpu-monitoring-memcache/86811/9 "2017-06-27T13:55:34Z")

</div>

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.
