Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

BUG - ParseHttp exception. Recovering, but please report this: runtime error: slice bounds out of range #6409

Closed
anergiti opened this issue Feb 19, 2018 · 19 comments

Comments

@anergiti
Copy link

anergiti commented Feb 19, 2018

Hello,
Opening a bug issue per elasticteam request:

Hello.
im running packetbeat; Version: 6.2.1 on ubuntu machine,
Connected to Elasticsearch version 5.1.2.
capturing mirrored traffic.

this is my yml file:

`packetbeat.interfaces.device: eth5
packetbeat.interfaces.type: af_packet
packetbeat.interfaces.snaplen: 1500
packetbeat.interfaces.buffer_size_mb: 500
packetbeat.flows:
ports: [53]

include_authorities controls whether or not the dns.authorities field
(authority resource records) is added to messages.
include_authorities: true

include_additionals controls whether or not the dns.additionals field
(additional resource records) is added to messages.
include_additionals: true

type: http
Configure the ports where to listen for HTTP traffic. You can disable
the HTTP protocol by commenting out the list of ports.
enabled: true
ports: [80, 8080]
send_headers: false
send_all_headers: false
include_body_for: ["application/json"]
send_request: true
send_response: true
transaction_timeout: 20s
output.elasticsearch:

Array of hosts to connect to.
hosts: ["1.1.1.1:9200"]`

most of packets are not parsed due to ParseHttp exception - slice bounds out of range.

This is a snip of debug logs of Packetbeat:

2018-02-16T13:59:05.332-0500	INFO	instance/beat.go:468	Home path: [/usr/share/packetbeat/bin] Config path: [/usr/share/packetbeat/bin] Data path: [/usr/share/packetbeat/bin/data] Logs path: [/usr/share/packetbeat/bin/logs]
2018-02-16T13:59:05.335-0500	INFO	instance/beat.go:475	Beat UUID: 418b8929-9abc-4c5b-9c17-ff0e13fd876e
2018-02-16T13:59:05.335-0500	INFO	instance/beat.go:213	Setup Beat: packetbeat; Version: 6.2.1
2018-02-16T13:59:05.335-0500	INFO	elasticsearch/client.go:145	Elasticsearch url: http://myelasticserver:9200
2018-02-16T13:59:05.335-0500	INFO	pipeline/module.go:76	Beat name: server.name.fqdn
2018-02-16T13:59:05.336-0500	INFO	procs/procs.go:78	Process matching disabled
2018-02-16T13:59:05.340-0500	INFO	instance/beat.go:301	packetbeat start running.
2018-02-16T13:59:05.340-0500	INFO	[monitoring]	log/log.go:97	Starting metrics logging every 30s
2018-02-16T13:59:22.423-0500	ERROR	runtime/panic.go:35	ParseHttp exception. Recovering, but please report this: runtime error: slice bounds out of range.	{"stack": "github.com/elastic/beats/libbeat/logp.Recover\n\t/go/src/github.com/elastic/beats/libbeat/logp/global.go:88\nruntime.call32\n\t/usr/local/go/src/runtime/asm_amd64.s:509\nruntime.gopanic\n\t/usr/local/go/src/runtime/panic.go:491\nruntime.panicslice\n\t/usr/local/go/src/runtime/panic.go:35\ngithub.com/elastic/beats/packetbeat/protos/http.(*parser).parseHTTPLine\n\t/go/src/github.com/elastic/beats/packetbeat/protos/http/http_parser.go:179\ngithub.com/elastic/beats/packetbeat/protos/http.(*parser).parse\n\t/go/src/github.com/elastic/beats/packetbeat/protos/http/http_parser.go:107\ngithub.com/elastic/beats/packetbeat/protos/http.(*httpPlugin).doParse\n\t/go/src/github.com/elastic/beats/packetbeat/protos/http/http.go:293\ngithub.com/elastic/beats/packetbeat/protos/http.(*httpPlugin).Parse\n\t/go/src/github.com/elastic/beats/packetbeat/protos/http/http.go:224\ngithub.com/elastic/beats/packetbeat/protos/tcp.(*TCPStream).addPacket\n\t/go/src/github.com/elastic/beats/packetbeat/protos/tcp/tcp.go:115\ngithub.com/elastic/beats/packetbeat/protos/tcp.(*TCP).Process\n\t/go/src/github.com/elastic/beats/packetbeat/protos/tcp/tcp.go:208\ngithub.com/elastic/beats/packetbeat/decoder.(*Decoder).onTCP\n\t/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:317\ngithub.com/elastic/beats/packetbeat/decoder.(*Decoder).process\n\t/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:258\ngithub.com/elastic/beats/packetbeat/decoder.(*Decoder).OnPacket\n\t/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:164\ngithub.com/elastic/beats/packetbeat/sniffer.(*Sniffer).Run\n\t/go/src/github.com/elastic/beats/packetbeat/sniffer/sniffer.go:193\ngithub.com/elastic/beats/packetbeat/beater.(*packetbeat).Run.func2\n\t/go/src/github.com/elastic/beats/packetbeat/beater/packetbeat.go:202"}
2018-02-16T13:59:35.342-0500	INFO	[monitoring]	log/log.go:124	Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":10810,"time":10818},"total":{"ticks":58880,"time":58888,"value":58880},"user":{"ticks":48070,"time":48070}},"info":{"ephemeral_id":"a78c6431-fe65-4b55-9c43-624537eac328","uptime":{"ms":30015}},"memstats":{"gc_next":7913065664,"memory_alloc":5098753768,"memory_total":10229529576,"rss":6588616704}},"http":{"unmatched_responses":315004},"libbeat":{"config":{"module":{"running":0}},"output":{"type":"elasticsearch"},"pipeline":{"clients":12,"events":{"active":0}}},"system":{"cpu":{"cores":32},"load":{"1":1.83,"15":1.31,"5":1.57,"norm":{"1":0.0572,"15":0.0409,"5":0.0491}}},"tcp":{"dropped_because_of_gaps":14523}}}}
2018-02-16T14:00:05.342-0500	INFO	[monitoring]	log/log.go:124	Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":18710,"time":18712},"total":{"ticks":105240,"time":105243,"value":105240},"user":{"ticks":86530,"time":86531}},"info":{"ephemeral_id":"a78c6431-fe65-4b55-9c43-624537eac328","uptime":{"ms":60014}},"memstats":{"gc_next":7542307872,"memory_alloc":7108923240,"memory_total":19867083776,"rss":2189402112}},"http":{"unmatched_responses":297639},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":12,"events":{"active":0}}},"system":{"load":{"1":2.12,"15":1.35,"5":1.66,"norm":{"1":0.0663,"15":0.0422,"5":0.0519}}},"tcp":{"dropped_because_of_gaps":18712}}}}
2018-02-16T14:00:15.803-0500	INFO	beater/packetbeat.go:221	Packetbeat send stop signal
2018-02-16T14:00:15.884-0500	INFO	instance/beat.go:308	packetbeat stopped.
2018-02-16T14:00:15.885-0500	INFO	[monitoring]	log/log.go:132	Total non-zero metrics	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":22060,"time":22065},"total":{"ticks":130490,"time":130496,"value":130490},"user":{"ticks":108430,"time":108431}},"info":{"ephemeral_id":"a78c6431-fe65-4b55-9c43-624537eac328","uptime":{"ms":70557}},"memstats":{"gc_next":7383853248,"memory_alloc":4384858264,"memory_total":23284031896,"rss":8257155072}},"http":{"unmatched_responses":716837},"libbeat":{"config":{"module":{"running":0}},"output":{"type":"elasticsearch"},"pipeline":{"clients":12,"events":{"active":0}}},"system":{"cpu":{"cores":32},"load":{"1":2.24,"15":1.37,"5":1.7,"norm":{"1":0.07,"15":0.0428,"5":0.0531}}},"tcp":{"dropped_because_of_gaps":39174}}}}
2018-02-16T14:00:15.885-0500	INFO	[monitoring]	log/log.go:133	Uptime: 1m10.558590286s
2018-02-16T14:00:15.885-0500	INFO	[monitoring]	log/log.go:110	Stopping metrics logging.
@andrewkroh
Copy link
Member

Based on the stack trace it looks like a slice indexing bug while attempting to parse the HTTP header. @anergiti Would you be able to capture a short trace and attach it here so we can replay the data through Packetbeat?

runtime.panicslice
	/usr/local/go/src/runtime/panic.go:35
github.com/elastic/beats/packetbeat/protos/http.(*parser).parseHTTPLine
	/go/src/github.com/elastic/beats/packetbeat/protos/http/http_parser.go:179
github.com/elastic/beats/packetbeat/protos/http.(*parser).parse
	/go/src/github.com/elastic/beats/packetbeat/protos/http/http_parser.go:107
github.com/elastic/beats/packetbeat/protos/http.(*httpPlugin).doParse
	/go/src/github.com/elastic/beats/packetbeat/protos/http/http.go:293
github.com/elastic/beats/packetbeat/protos/http.(*httpPlugin).Parse
	/go/src/github.com/elastic/beats/packetbeat/protos/http/http.go:224
github.com/elastic/beats/packetbeat/protos/tcp.(*TCPStream).addPacket
	/go/src/github.com/elastic/beats/packetbeat/protos/tcp/tcp.go:115
github.com/elastic/beats/packetbeat/protos/tcp.(*TCP).Process
	/go/src/github.com/elastic/beats/packetbeat/protos/tcp/tcp.go:208
github.com/elastic/beats/packetbeat/decoder.(*Decoder).onTCP
	/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:317
github.com/elastic/beats/packetbeat/decoder.(*Decoder).process
	/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:258
github.com/elastic/beats/packetbeat/decoder.(*Decoder).OnPacket
	/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:164
github.com/elastic/beats/packetbeat/sniffer.(*Sniffer).Run
	/go/src/github.com/elastic/beats/packetbeat/sniffer/sniffer.go:193
github.com/elastic/beats/packetbeat/beater.(*packetbeat).Run.func2
	/go/src/github.com/elastic/beats/packetbeat/beater/packetbeat.go:202"

And this looks similar to #2150.

https://github.com/elastic/beats/blob/v6.2.1/packetbeat/protos/http/http_parser.go#L179

@ph
Copy link
Contributor

ph commented Feb 20, 2018 via email

@anergiti
Copy link
Author

Hey @andrewkroh
Please see attached zipped pcap snip.
Thanks for helping here!

trace_summary.pcap.zip

@andrewkroh
Copy link
Member

I wasn't able to open the attached pcap file (after unzipping) with Packetbeat or Wireshark. I think it got corrupted somehow. Not sure if it was during the upload or something Packetbeat did while writing it. Sorry to ask, but can you try again?

@anergiti
Copy link
Author

Hey,
when trying to tail the file its seems as binary file. so its i dont think it`s corrupted.
tcpdump might help?

@andrewkroh
Copy link
Member

andrewkroh commented Feb 22, 2018

pcap files are not plain text so it is expected that tail doesn't work properly.

-dump produces the same file type as tcpdump -w, so yes, you could try tcpdump. You just need to setup the BPF filter the same as Packetbeat (like tcp port 80 or tcp port 8080).

The files produced by -dump should also be readable by tcpdump -r [file.pcap]. So please try that before uploading. Thanks!

@anergiti
Copy link
Author

mytrace.pcap.zip
hope this one good

@adriansr
Copy link
Contributor

Hi @anergiti , can you confirm that you get the runtime error when running this pcap through packetbeat? Because I don't seem to get it.

Try with:

packetbeat run -e -I mytrace.pcap
please note that the -I argument is an uppercase i

@anergiti
Copy link
Author

Yup you right.
i really dont get it.
while im running packetbeat with .pcap - all ok.
while running standalone (./packetbeat run -e -c /etc/packetbeat/packetbeat.yml) - lots of parsing errors.

is there a difference between pcap and standalone?

@adriansr
Copy link
Contributor

@anergiti can you try capturing more traffic with the -dump option and make sure that you see the errors in the log?

@anergiti
Copy link
Author

anergiti commented Mar 4, 2018

Sure, can try
cuz throughput is overwhelming.

@anergiti
Copy link
Author

anergiti commented Mar 5, 2018

guys im really @ dead end here.
pcap file reaches hundreds of MB which cannot be uploaded here.
anyway,
while running
./packetbeat -e -c /etc/packetbeat/packetbeat.yml -dump trace.pcap
i see the parsing errors - attached scrn shot.
screen shot 2018-03-05 at 15 25 18

while running ./packetbeat run -e -I trace.pcap
NO ERROR AT ALL.

i will be happy to set remote session (skype, hangout) if that`s possible.
thanks.

@anergiti
Copy link
Author

anergiti commented Apr 3, 2018

Hey. i have uploaded the pcap file. can download it from dropbox link bellow.
Thanks!

https://www.dropbox.com/s/3citcxi7ihiwmqw/trace.pcap?dl=0

adriansr added a commit to adriansr/beats that referenced this issue Apr 3, 2018
There was a bounds check error in parsing HTTP responses. A malformed
response line in the form "HTTP/1.1\r\n" would cause a panic when parsed.
andrewkroh pushed a commit that referenced this issue Apr 4, 2018
There was a bounds check error in parsing HTTP responses. A malformed
response line in the form "HTTP/1.1\r\n" would cause a panic when parsed.

Related to #6409
adriansr added a commit to adriansr/beats that referenced this issue Apr 5, 2018
There was a bounds check error in parsing HTTP responses. A malformed
response line in the form "HTTP/1.1\r\n" would cause a panic when parsed.

Related to elastic#6409
adriansr added a commit to adriansr/beats that referenced this issue Apr 5, 2018
There was a bounds check error in parsing HTTP responses. A malformed
response line in the form "HTTP/1.1\r\n" would cause a panic when parsed.

Related to elastic#6409
adriansr added a commit to adriansr/beats that referenced this issue Apr 6, 2018
There was a bounds check error in parsing HTTP responses. A malformed
response line in the form "HTTP/1.1\r\n" would cause a panic when parsed.

Related to elastic#6409
andrewkroh pushed a commit that referenced this issue Apr 6, 2018
There was a bounds check error in parsing HTTP responses. A malformed
response line in the form "HTTP/1.1\r\n" would cause a panic when parsed.

Related to #6409
andrewkroh pushed a commit that referenced this issue Apr 6, 2018
There was a bounds check error in parsing HTTP responses. A malformed
response line in the form "HTTP/1.1\r\n" would cause a panic when parsed.

Related to #6409
@anergiti
Copy link
Author

hey guys,
Thanks for taking care of this.
do you have an expectation of a solution?
thanks!

@anergiti
Copy link
Author

@andrewkroh how are you?
appreciate an update regarding this issue.
Thanks!

@adriansr
Copy link
Contributor

adriansr commented Apr 30, 2018

Hi @anergiti,

A fix for this problem (#6750) was included in 6.2.4.

@teotwaki
Copy link

@adriansr I just updated to 6.2.4, but still see this issue in production. I'm trying to figure out how to provide a pcap without sensitive data.

@adriansr
Copy link
Contributor

adriansr commented Apr 30, 2018

Can you provide the stacktrace reported by packetbeat?

@adriansr adriansr reopened this Apr 30, 2018
@teotwaki
Copy link

github.com/elastic/beats/libbeat/logp.Recover
	/go/src/github.com/elastic/beats/libbeat/logp/global.go:88
runtime.call32
	/usr/local/go/src/runtime/asm_amd64.s:509
runtime.gopanic
	/usr/local/go/src/runtime/panic.go:491
runtime.panicslice
	/usr/local/go/src/runtime/panic.go:35
github.com/elastic/beats/packetbeat/protos/http.(*parser).parseHTTPLine
	/go/src/github.com/elastic/beats/packetbeat/protos/http/http_parser.go:179
github.com/elastic/beats/packetbeat/protos/http.(*parser).parse
	/go/src/github.com/elastic/beats/packetbeat/protos/http/http_parser.go:107
github.com/elastic/beats/packetbeat/protos/http.(*httpPlugin).doParse
	/go/src/github.com/elastic/beats/packetbeat/protos/http/http.go:293
github.com/elastic/beats/packetbeat/protos/http.(*httpPlugin).Parse
	/go/src/github.com/elastic/beats/packetbeat/protos/http/http.go:224
github.com/elastic/beats/packetbeat/protos/tcp.(*TCPStream).addPacket
	/go/src/github.com/elastic/beats/packetbeat/protos/tcp/tcp.go:115
github.com/elastic/beats/packetbeat/protos/tcp.(*TCP).Process
	/go/src/github.com/elastic/beats/packetbeat/protos/tcp/tcp.go:208
github.com/elastic/beats/packetbeat/decoder.(*Decoder).onTCP
	/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:317
github.com/elastic/beats/packetbeat/decoder.(*Decoder).process
	/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:258
github.com/elastic/beats/packetbeat/decoder.(*Decoder).OnPacket
	/go/src/github.com/elastic/beats/packetbeat/decoder/decoder.go:164
github.com/elastic/beats/packetbeat/sniffer.(*Sniffer).Run
	/go/src/github.com/elastic/beats/packetbeat/sniffer/sniffer.go:193
github.com/elastic/beats/packetbeat/beater.(*packetbeat).Run.func2
	/go/src/github.com/elastic/beats/packetbeat/beater/packetbeat.go:202

adriansr added a commit to adriansr/beats that referenced this issue May 2, 2018
A broken HTTP request caused the parser to report a panic.

Fixes elastic#6409
ruflin pushed a commit that referenced this issue May 3, 2018
A broken HTTP request caused the parser to report a panic.

Fixes #6409
adriansr added a commit to adriansr/beats that referenced this issue May 9, 2018
A broken HTTP request caused the parser to report a panic.

Fixes elastic#6409
andrewkroh pushed a commit that referenced this issue May 9, 2018
A broken HTTP request caused the parser to report a panic.

Fixes #6409
adriansr added a commit to adriansr/beats that referenced this issue Jun 15, 2018
A broken HTTP request caused the parser to report a panic.

Fixes elastic#6409

(cherry picked from commit a634802)
ruflin pushed a commit that referenced this issue Jun 15, 2018
A broken HTTP request caused the parser to report a panic.

Fixes #6409

(cherry picked from commit a634802)
leweafan pushed a commit to leweafan/beats that referenced this issue Apr 28, 2023
…elastic#7339)

A broken HTTP request caused the parser to report a panic.

Fixes elastic#6409

(cherry picked from commit 73a009f)
leweafan pushed a commit to leweafan/beats that referenced this issue Apr 28, 2023
There was a bounds check error in parsing HTTP responses. A malformed
response line in the form "HTTP/1.1\r\n" would cause a panic when parsed.

Related to elastic#6409
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

5 participants