ParseMemcache(UDP) exception: invalid memory address or nil pointer dereference

codekoala · August 12, 2016, 8:53pm

Using packetbeat version 1.2.3 (amd64) on Arch Linux with the default configuration, I received the following output:

2016/08/12 20:00:46.305470 log.go:113: ERR ParseMemcache(UDP) exception. Recovering, but please report this: runtime error: invalid memory address or nil pointer dereference.
2016/08/12 20:00:46.305538 log.go:114: ERR Stacktrace: goroutine 37 [running]:
runtime/debug.Stack(0x0, 0x0, 0x0)
        /usr/lib/go/src/runtime/debug/stack.go:24 +0x80
github.com/elastic/beats/libbeat/logp.Recover(0xb760a0, 0x1c)
        /build/beats/src/gopath/src/github.com/elastic/beats/libbeat/logp/log.go:114 +0x166
panic(0xa07040, 0xc82000e100)
        /usr/lib/go/src/runtime/panic.go:443 +0x4e9
github.com/elastic/beats/packetbeat/protos/memcache.(*Memcache).onUdpMessage(0xc820092180, 0xc8213140c0, 0xc821252018, 0x1074101, 0x0, 0x0, 0x0, 0x0)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/protos/memcache/plugin_udp.go:163 +0x5c
github.com/elastic/beats/packetbeat/protos/memcache.(*Memcache).ParseUdp(0xc820092180, 0xc821252000)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/protos/memcache/plugin_udp.go:122 +0x9bc
github.com/elastic/beats/packetbeat/protos/udp.(*Udp).Process(0xc8212c7740, 0xc821252000)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/protos/udp/udp.go:58 +0x429
github.com/elastic/beats/packetbeat/decoder.(*DecoderStruct).process(0xc8211f0000, 0xc821252000, 0x2d, 0x0, 0x0)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:170 +0x51e
github.com/elastic/beats/packetbeat/decoder.(*DecoderStruct).DecodePacketData(0xc8211f0000, 0xc8201d05c4, 0x71, 0x71, 0xc821827ed8)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:101 +0x312
github.com/elastic/beats/packetbeat/sniffer.(*SnifferSetup).Run(0xc821220a00, 0x0, 0x0)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/sniffer/sniffer.go:356 +0xb55
github.com/elastic/beats/packetbeat/beat.(*Packetbeat).Run.func1(0xc82009e480)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/beat/packetbeat.go:232 +0x37
created by github.com/elastic/beats/packetbeat/beat.(*Packetbeat).Run
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/beat/packetbeat.go:238 +0x45
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x170 pc=0x4d96a9]

goroutine 50 [running]:
panic(0xa07040, 0xc82000e100)
        /usr/lib/go/src/runtime/panic.go:481 +0x3e6
github.com/elastic/beats/packetbeat/protos/memcache.(*transaction).Event(0x0, 0xc8211895c0, 0x0, 0x0)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/protos/memcache/memcache.go:357 +0x39
github.com/elastic/beats/packetbeat/protos/memcache.(*Memcache).onTransaction(0xc820092180, 0x0)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/protos/memcache/memcache.go:176 +0x62
github.com/elastic/beats/packetbeat/protos/memcache.(*Memcache).finishTransaction(0xc820092180, 0x0, 0x0, 0x0)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/protos/memcache/memcache.go:170 +0x50
github.com/elastic/beats/packetbeat/protos/memcache.(*Memcache).onUdpTrans(0xc820092180, 0xc8213140c0, 0x0, 0x0)
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/protos/memcache/plugin_udp.go:198 +0x87
github.com/elastic/beats/packetbeat/protos/memcache.(*Memcache).ParseUdp.func1()
        /build/beats/src/gopath/src/github.com/elastic/beats/packetbeat/protos/memcache/plugin_udp.go:132 +0x72
created by time.goFunc
        /usr/lib/go/src/time/sleep.go:129 +0x3a

I didn't see this particular issue mentioned anywhere. Issue issue #299 on GitHub looks fairly similar, but it looks like it was closed before v1.0.0.

monica · August 13, 2016, 5:17am

Thank you @codekoala for reporting the issue. Are you able to easily reproduce the issue? It would be nice if you can send me by email (monica@elastic.co) a small pcap trace with the memcache traffic that caused the crash, so we can easily reproduce and fix the problem. Please have a look here for more details about how to create the trace.

codekoala · August 13, 2016, 5:31am

The most surprising thing about this error to me is that I got it on my home machine, where there is no memcache traffic that I'm aware of. I haven't used memcache for many years.

I noticed it when I had packetbeat running in a terminal (as opposed to running as a daemon) and left my computer for lunch. When I got back some 30 minutes later, I noticed the trace and packetbeat was dead. I haven't seen the error before or since :-/

steffens · August 13, 2016, 3:01pm

There is still a chance some other protocol using the default memcache port? A trace with tcpdump would help figuring this out.
you saying packetbeat was killed by this panic? That's weird, normally the protocol analyzer a supposed to capture and recover from these panics, so packetbeat can continue processing. Even if source is not memcache it's interesting to investigate in this case.

codekoala · August 13, 2016, 7:23pm

I can certainly leave tcpdump up for a while to see if anything decides to use the memcache port.

I thought it was strange that the panic wasn't recovered nicely too, since the message said it was recovering at the very start. I actually had another instance of packetbeat running inside LXC on the same machine that this error appeared (at the same time). That instance of packetbeat had the same ParseMemcache error at the same time, but it continued running as expected.

codekoala · August 14, 2016, 12:33am

So far I've let tcpdump look for memcache traffic on my box for about 5 hours. Not a single packet yet. I'm going to leave both packetbeat and tcpdump to just run for a while to see if it happens again.

codekoala · August 19, 2016, 6:09am

I've kept the same instance of packetbeat and tcpdump running since my last post. I've got a 90GB pcap file sitting on my disk. Not once has tcpdump noticed any memcache traffic, and I've not seen the original error again.

I did, however, see https://github.com/elastic/beats/issues/2150. I'll be updating that issue with a snippet of the pcap file if I can

steffens · August 19, 2016, 2:39pm

Thanks for testing. Muuuuuuch appreciated!!!

Looking forward for #2150 update.

You can test pcap file with packetbeat -c <config file> -I <pcap file> -N -e -t. This will analyze the pcap as fast as possible + disables all outputs.

system · September 2, 2016, 8:53pm

This topic was automatically closed after 21 days. New replies are no longer allowed.