packetbeat SIGSEV segmentation violation

[philippkahr]

OS: UnRaid 6.9.3 running Docker Version 20.10.5
Packetbeat version: 7.13.0

I am running packetbeat 7.13.0 on unraid 6.9.3 with a Docker container. I've attached the packetbeat.yml, the log details that show up.

panic: runtime error: invalid memory address or nil pointer dereference

[signal SIGSEGV: segmentation violation code=0x1 addr=0x220 pc=0x55c315823659]

From the monitoring tab I cannot see anything wrong. I debugged packetbeat with the --httpproof option here you go:
packetbeatdebug.zip I collected the following each minute: http://192.168.0.252:8888/debug/pprof/heap?gc=1

The issue is that it happens at random.

Packetbeat.yml

packetbeat.interfaces.device: br0

packetbeat.interfaces.internal_networks:
  - private
  - 
packetbeat.flows:
  # Set network flow timeout. Flow is killed if no packet is received before being
  # timed out.
  timeout: 30s

  # Configure reporting period. If set to -1, only killed flows will be reported
  period: 10s

# =========================== Transaction protocols ============================

packetbeat.protocols:
- type: icmp
  # Enable ICMPv4 and ICMPv6 monitoring. The default is true.
  enabled: true

- type: amqp
  # Configure the ports where to listen for AMQP traffic. You can disable
  # the AMQP protocol by commenting out the list of ports.
  ports: [5672]

- type: cassandra
  # Configure the ports where to listen for Cassandra traffic. You can disable
  # the Cassandra protocol by commenting out the list of ports.
  ports: [9042]

- type: dhcpv4
  # Configure the DHCP for IPv4 ports.
  ports: [67, 68]

- type: dns
  # Configure the ports where to listen for DNS traffic. You can disable
  # the DNS protocol by commenting out the list of ports.
  ports: [53]

- type: http
  # Configure the ports where to listen for HTTP traffic. You can disable
  # the HTTP protocol by commenting out the list of ports.
  ports: [80, 8080, 8000, 5000, 8002, 8989]

- type: memcache
  # Configure the ports where to listen for memcache traffic. You can disable
  # the Memcache protocol by commenting out the list of ports.
  ports: [11211]

- type: mysql
  # Configure the ports where to listen for MySQL traffic. You can disable
  # the MySQL protocol by commenting out the list of ports.
  ports: [3306,3307]

- type: pgsql
  # Configure the ports where to listen for Pgsql traffic. You can disable
  # the Pgsql protocol by commenting out the list of ports.
  ports: [5432]

- type: redis
  # Configure the ports where to listen for Redis traffic. You can disable
  # the Redis protocol by commenting out the list of ports.
  ports: [6379]

- type: thrift
  # Configure the ports where to listen for Thrift-RPC traffic. You can disable
  # the Thrift-RPC protocol by commenting out the list of ports.
  ports: [9090]

- type: mongodb
  # Configure the ports where to listen for MongoDB traffic. You can disable
  # the MongoDB protocol by commenting out the list of ports.
  ports: [27017]

- type: nfs
  # Configure the ports where to listen for NFS traffic. You can disable
  # the NFS protocol by commenting out the list of ports.
  ports: [2049]

- type: tls
  # Configure the ports where to listen for TLS traffic. You can disable
  # the TLS protocol by commenting out the list of ports.
  ports:
    - 443   # HTTPS
    - 993   # IMAPS
    - 995   # POP3S
    - 5223  # XMPP over SSL
    - 8443
    - 8883  # Secure MQTT
    - 9243  # Elasticsearch

- type: sip
  # Configure the ports where to listen for SIP traffic. You can disable
  # the SIP protocol by commenting out the list of ports.
  ports: [5060]

# ======================= Elasticsearch template setting =======================

setup.template.settings:
  index.number_of_shards: 1
  #index.codec: best_compression
  #_source.enabled: false

# =============================== Elastic Cloud ================================

cloud.id: fancy-elastic-cloudID
cloud.auth: super-cool-password

# ================================= Processors =================================

processors:
  - # Add forwarded to tags when processing data from a network tap or mirror.
    if.contains.tags: forwarded
    then:
      - drop_fields:
          fields: [host]
    else:
      - add_host_metadata: ~
  - add_cloud_metadata: ~
  - add_docker_metadata: ~
  - detect_mime_type:
      field: http.request.body.content
      target: http.request.mime_type
  - detect_mime_type:
      field: http.response.body.content
      target: http.response.mime_type

monitoring.enabled: true

Docker details

Client: Docker Engine - Community
 Version:           20.10.5
 API version:       1.41
 Go version:        go1.13.15
 Git commit:        55c4c88
 Built:             Tue Mar  2 20:14:11 2021
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          20.10.5
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.13.15
  Git commit:       363e9a8
  Built:            Tue Mar  2 20:18:31 2021
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          v1.4.3
  GitCommit:        269548fa27e0089a8b8278fc4fc781d7f65a939b
 runc:
  Version:          1.0.0-rc93
  GitCommit:        12644e614e25b05da6fd08a38ffa0cfe1903fdec
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0

Detailed error log

2021-05-31T17:23:14.845Z INFO [monitoring] log/log.go:144 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cgroup":{"cpu":{"cfs":{"period":{"us":100000}},"id":"c4685776e72a48f149c8d3133730643f47a03ce2a2aec3c4fa0038f539499402"},"cpuacct":{"id":"c4685776e72a48f149c8d3133730643f47a03ce2a2aec3c4fa0038f539499402","total":{"ns":785767736}},"memory":{"id":"c4685776e72a48f149c8d3133730643f47a03ce2a2aec3c4fa0038f539499402","mem":{"limit":{"bytes":9223372036854771712},"usage":{"bytes":119943168}}}},"cpu":{"system":{"ticks":160,"time":{"ms":167}},"total":{"ticks":740,"time":{"ms":752},"value":740},"user":{"ticks":580,"time":{"ms":585}}},"handles":{"limit":{"hard":40960,"soft":40960},"open":11},"info":{"ephemeral_id":"fe2bf057-6a0e-46d0-be97-859aa9251044","uptime":{"ms":30134}},"memstats":{"gc_next":48959840,"memory_alloc":43075720,"memory_sys":77308058,"memory_total":85219400,"rss":151367680},"runtime":{"goroutines":60}},"dns":{"unmatched_requests":2,"unmatched_responses":2},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":263,"active":0,"batches":17,"total":263},"read":{"bytes":15796},"type":"elasticsearch","write":{"bytes":517688}},"pipeline":{"clients":30,"events":{"active":0,"published":263,"retry":12,"total":263},"queue":{"acked":263,"max_events":4096}}},"system":{"cpu":{"cores":8},"load":{"1":0.58,"15":0.27,"5":0.3,"norm":{"1":0.0725,"15":0.0338,"5":0.0375}}}}}}
2021-05-31T17:23:44.844Z INFO [monitoring] log/log.go:144 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cgroup":{"cpuacct":{"total":{"ns":399494857}},"memory":{"mem":{"usage":{"bytes":16031744}}}},"cpu":{"system":{"ticks":270,"time":{"ms":112}},"total":{"ticks":1140,"time":{"ms":403},"value":1140},"user":{"ticks":870,"time":{"ms":291}}},"handles":{"limit":{"hard":40960,"soft":40960},"open":11},"info":{"ephemeral_id":"fe2bf057-6a0e-46d0-be97-859aa9251044","uptime":{"ms":60133}},"memstats":{"gc_next":55121552,"memory_alloc":46569208,"memory_sys":69274632,"memory_total":131940528,"rss":167911424},"runtime":{"goroutines":60}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":444,"active":0,"batches":20,"total":444},"read":{"bytes":13319},"write":{"bytes":743537}},"pipeline":{"clients":30,"events":{"active":0,"published":444,"total":444},"queue":{"acked":444}}},"system":{"load":{"1":0.35,"15":0.26,"5":0.27,"norm":{"1":0.0438,"15":0.0325,"5":0.0338}}}}}}
2021-05-31T17:24:14.844Z INFO [monitoring] log/log.go:144 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cgroup":{"cpuacct":{"total":{"ns":436324019}},"memory":{"mem":{"usage":{"bytes":9486336}}}},"cpu":{"system":{"ticks":410,"time":{"ms":140}},"total":{"ticks":1580,"time":{"ms":436},"value":1580},"user":{"ticks":1170,"time":{"ms":296}}},"handles":{"limit":{"hard":40960,"soft":40960},"open":11},"info":{"ephemeral_id":"fe2bf057-6a0e-46d0-be97-859aa9251044","uptime":{"ms":90133}},"memstats":{"gc_next":79057664,"memory_alloc":53410600,"memory_total":180194240,"rss":177287168},"runtime":{"goroutines":60}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":370,"active":0,"batches":21,"total":370},"read":{"bytes":13399},"write":{"bytes":660941}},"pipeline":{"clients":30,"events":{"active":0,"published":370,"total":370},"queue":{"acked":370}}},"system":{"load":{"1":0.41,"15":0.27,"5":0.29,"norm":{"1":0.0513,"15":0.0338,"5":0.0363}}}}}}
2021-05-31T17:24:44.845Z INFO [monitoring] log/log.go:144 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cgroup":{"cpuacct":{"total":{"ns":370518822}},"memory":{"mem":{"usage":{"bytes":729088}}}},"cpu":{"system":{"ticks":540,"time":{"ms":122}},"total":{"ticks":1950,"time":{"ms":364},"value":1950},"user":{"ticks":1410,"time":{"ms":242}}},"handles":{"limit":{"hard":40960,"soft":40960},"open":11},"info":{"ephemeral_id":"fe2bf057-6a0e-46d0-be97-859aa9251044","uptime":{"ms":120134}},"memstats":{"gc_next":70277264,"memory_alloc":57751184,"memory_total":225924416,"rss":178421760},"runtime":{"goroutines":60}},"libbeat":{"config":{"module":{"running":0}},"output":{"events":{"acked":314,"active":0,"batches":16,"total":314},"read":{"bytes":10362},"write":{"bytes":527185}},"pipeline":{"clients":30,"events":{"active":0,"published":314,"total":314},"queue":{"acked":314}}},"system":{"load":{"1":0.63,"15":0.3,"5":0.37,"norm":{"1":0.0788,"15":0.0375,"5":0.0463}}}}}}
panic: runtime error: invalid memory address or nil pointer dereference

[signal SIGSEGV: segmentation violation code=0x1 addr=0x220 pc=0x55c315823659]

goroutine 132 [running]:
github.com/elastic/beats/v7/packetbeat/protos/memcache.(*transaction).Event(0x0, 0xc0005d1ed0, 0x55c316c24900, 0xc001c6c0d0)
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/memcache.go:387 +0x39
github.com/elastic/beats/v7/packetbeat/protos/memcache.(*memcache).onTransaction(0xc000162ea0, 0x0)
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/memcache.go:207 +0x71
github.com/elastic/beats/v7/packetbeat/protos/memcache.(*memcache).finishTransaction(...)
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/memcache.go:199
github.com/elastic/beats/v7/packetbeat/protos/memcache.(*memcache).onUDPTrans(0xc000162ea0, 0xc003a860c0, 0x0, 0x0)
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/plugin_udp.go:213 +0x96
github.com/elastic/beats/v7/packetbeat/protos/memcache.(*memcache).ParseUDP.func1()
/go/src/github.com/elastic/beats/packetbeat/protos/memcache/plugin_udp.go:148 +0x7e
created by time.goFunc
/usr/local/go/src/time/sleep.go:167 +0x46

process information log event

2021-05-31T18:16:32.365Z INFO [beat] instance/beat.go:1059 Process info {"system_info": {"process": {"capabilities": {"inheritable":["chown","dac_override","fowner","fsetid","kill","setgid","setuid","setpcap","net_bind_service","net_admin","net_raw","sys_chroot","mknod","audit_write","setfcap"],"permitted":["net_admin","net_raw"],"effective":["net_admin","net_raw"],"bounding":["chown","dac_override","fowner","fsetid","kill","setgid","setuid","setpcap","net_bind_service","net_admin","net_raw","sys_chroot","mknod","audit_write","setfcap"],"ambient":null}, "cwd": "/usr/share/packetbeat", "exe": "/usr/share/packetbeat/packetbeat", "name": "packetbeat", "pid": 7, "ppid": 1, "seccomp": {"mode":"filter","no_new_privs":true}, "start_time": "2021-05-31T18:16:30.140Z"}}}

[elasticmachine]

Pinging @elastic/security-external-integrations (Team:Security-External Integrations)

[andrewstucki]

I'd have to delve into the protocol a bit more to see what we should be doing here, but it looks like we're failing to nil check this case properly:

beats/packetbeat/protos/memcache/memcache.go

Lines 344 to 347 in a300f1b

	func newTransaction(requ, resp *message) *transaction {
	if requ == nil && resp == nil {
	return nil
	}

Here's the code from the included stacktrace.

First, the call to newTransaction and subsequently passing a potential nil to mc.finishTransaction:

beats/packetbeat/protos/memcache/plugin_udp.go

Lines 210 to 214 in a300f1b

	func (mc *memcache) onUDPTrans(udp *udpTransaction) error {
	debug("received memcache(udp) transaction")
	trans := newTransaction(udp.request, udp.response)
	return mc.finishTransaction(trans)
	}

Next, passing that on to onTransaction:

beats/packetbeat/protos/memcache/memcache.go

Lines 198 to 201 in a300f1b

	func (mc *memcache) finishTransaction(t *transaction) error {
	mc.handler.onTransaction(t)
	return nil
	}

Passing it on and invoking a method on it:

beats/packetbeat/protos/memcache/memcache.go

Lines 203 to 207 in a300f1b

	func (mc *memcache) onTransaction(t *transaction) {
	event := beat.Event{
	Fields: common.MapStr{},
	}
	t.Event(&event)

Dereferencing it as a part of a debug statement -- t.Notes which panics:

beats/packetbeat/protos/memcache/memcache.go

Lines 386 to 387 in a300f1b

	func (t *transaction) Event(event *beat.Event) error {
	debug("count event notes: %v", len(t.Notes))

I'm going to assume we probably just want to no-op the transaction if for some reason it's nil rather than continuing to try and process it, probably an if trans == nil guard right before the call to mc.finishTransaction in both the UDP and TCP handlers.

[botelastic]

Hi!
We just realized that we haven't looked into this issue in a while. We're sorry!

We're labeling this issue as Stale to make it hit our filters and make sure we get back to it as soon as possible. In the meantime, it'd be extremely helpful if you could take a look at it as well and confirm its relevance. A simple comment with a nice emoji will be enough :+1.
Thank you for your contribution!

[philippkahr]

:+1

[botelastic]

Hi!
We just realized that we haven't looked into this issue in a while. We're sorry!

We're labeling this issue as Stale to make it hit our filters and make sure we get back to it as soon as possible. In the meantime, it'd be extremely helpful if you could take a look at it as well and confirm its relevance. A simple comment with a nice emoji will be enough :+1.
Thank you for your contribution!

[elasticmachine]

Pinging @elastic/sec-linux-platform (Team:Security-Linux Platform)

[botelastic]

Hi!
We just realized that we haven't looked into this issue in a while. We're sorry!

We're labeling this issue as Stale to make it hit our filters and make sure we get back to it as soon as possible. In the meantime, it'd be extremely helpful if you could take a look at it as well and confirm its relevance. A simple comment with a nice emoji will be enough :+1.
Thank you for your contribution!

[fearful-symmetry]

Fixed by #33853