Libhtp::request_uri_not_seen

Help
1

Hello

description

Network traffic is duplicated by multiple F5 hardware LB and sent to multiple VMs (arping with custom mac to update F5 arptable). At VM it’s captured by suricata and metadata is stored in redis (via redis.sock).
Every few seconds there is at least one entry with "url":"/libhtp::request_uri_not_seen".

There were even more but after VM network interface type modification and disabling GRO/LRO we managed to reduce it to the number mentioned above.

ethtool --show-offload ens36 | grep receive-offload
generic-receive-offload: off
large-receive-offload: off [fixed]

Any ideas how to eliminate this or what’s causing it will be highly appreciated.

log

{"timestamp":"2022-02-09T15:53:02.272847+0100","flow_id":1019448412906245,"in_iface":"ens36","event_type":"alert","src_ip":"188.42.196.115","src_port":443,"dest_ip":"100.68.125.135","dest_port":57148,"proto":"TCP","tx_id":0,"alert":{"action":"allowed","gid":1,"signature_id":13,"rev":0,"signature":"","category":"","severity":3},"http":{"http_port":0,"url":"/libhtp::request_uri_not_seen","http_content_type":"text/html","status":408,"length":110,"http_response_body":"PGh0bWw+PGJvZHk+PGgxPjQwOCBSZXF1ZXN0IFRpbWUtb3V0PC9oMT4KWW91ciBicm93c2VyIGRpZG4ndCBzZW5kIGEgY29tcGxldGUgcmVxdWVzdCBpbiB0aW1lLgo8L2JvZHk+PC9odG1sPgo="},"files":[{"filename":"/libhtp::request_uri_not_seen","sid":[],"magic":"HTML document, ASCII text","gaps":false,"state":"CLOSED","sha256":"5b80b1566219a6c3321b14127ebae23f73a18fd50a0751d2179e42d461e9ad39","stored":false,"size":110,"tx_id":0}],"app_proto":"http","flow":{"pkts_toserver":5,"pkts_toclient":3,"bytes_toserver":332,"bytes_toclient":439,"start":"2022-02-09T15:49:40.107269+0100"},"host":"<remove>"}

version

suricata 6.0.2
docker container in ubuntu 20.04.3 LTS
VMware VM with E1000 network interface

rules:

  • alert http any any -> any any (http_content_type; content:"application/json"; sid:7;)
  • alert http any any -> any any (http_content_type; content:"application/ld+json"; sid:8;)
  • alert http any any -> any any (http_content_type; content:"application/x-httpd-php"; sid:9;)
  • alert http any any -> any any (http_content_type; content:"application/xml"; sid:10;)
  • alert http any any -> any any (http_content_type; content:"application/xhtml+xml"; sid:11;)
  • alert http any any -> any any (http_content_type; content:"text/plain"; sid:12;)
  • alert http any any -> any any (http_content_type; content:"text/html"; sid:13;)
  • alert http any any -> any any (http_content_type; content:"text/xml"; sid:14;)
  • alert http any any -> any any (http_content_type; content:"text/csv"; sid:15;)
  • alert http any any -> any any (content:"POST"; http_method; sid:16;)
  • pass http any any -> any any (msg:"IMAGE"; http_content_type; content:"image"; filestore; sid:1;)
  • pass http any any -> any any (msg:"VIDEO"; http_content_type; content:"video"; filestore; sid:2;)
2

Can you reproduce it and ideally with a pcap of that traffic?

3

Hello Andreas

Thank you for responding.
Please find attached pcap with packets that cover the time mentioned in previously listed log.

$ tcpdump -r tcpdump-138.pcap | sed -n '1s/ IP.*//p;$s/ IP.*//p'
reading from file tcpdump-138.pcap, link-type EN10MB (Ethernet)
15:53:02.259817
15:53:02.304964

tcpdump-138.pcap (977.3 KB)

If wider time range or additional data is required I’ll be happy to deliver.

$ tcpdump --version
tcpdump version 4.9.3
libpcap version 1.9.1 (with TPACKET_V3)
OpenSSL 1.1.1f  31 Mar 2020

tcpdump original flags: -K -n -G 60 'not icmp and tcp'

4

Hmm this is HTTP over Port 443?
Can you also share your config?
I can’t reproduce the alerts locally with those rules and this pcap with the default config.

5

Sure. Here is the config
suricata.yaml (70.8 KB)

6

Can you reproduce those alerts when you run the pcap via -r option in Suricata as well or just with live traffic?

7

Only live at the moment.
I can arrange a host for tcpreplay but it’ll take some time.

8

Is there any sort of decryption upfront?

but yes, try to get an example where you can reproduce it with a pcap in -r mode

9

No decryption that I’m aware of.
Working on setup to replay pcap…

10

Replaying pcap (suricata -r neither tcpreplay) uri_not_seen doesn’t appear.
However for live traffic still at least one entry per second. :confused:

I’m not a network expert but is it possible that tcpdump dumps packets after they are i.e. reordered into proper sequence?

11

So when looking into libhtp/htp/htp_response.c I would argue that it might be missing parts of the package. There could be many reasons.

Can you check the stats.log and ideally paste it here? Maybe there are some drops or other issues with the capture method used by suricata.

12

Suricata stats are already collected, with 30s interval, but in json format.
suricata-stats.json (504.4 KB)
Please let me know whether the same in stats.log format is required.

13

Doesn’t look that bad, do you have some stats on how often (percentage) this happens?

The tcpdump runs happened on the same docker container right?
I would argue that it must be somehow related to the capture method. But not sure yet why.

How do you run suricata with what type of args?

14

Hi anreas
we run suricata like that:

  • SURICATA_OPTIONS=-i ens36 -vvv -c /opt/suricata.yaml --set outputs.11.file-store.dir=/mnt/ceph_storage/suricata/filestore/{{.Node.Hostname}}-suricata

the tcpdump was taken from host (from interface which is attached to docker container). when we l look at the messages in redis uri_not_seen occurs very often

example.log (3.5 KB)

15

So the tcpdump was not from within the container?

16

Hello Andreas
Sorry for late response.

Correct. Previously attached pcap was from OS level.

Here is the one from within the container
tcpdump-205.pcap (976.9 KB)

$ tcpdump -r tcpdump-205.pcap | sed -n '1s/ IP.*//p;$s/ IP.*//p'
reading from file tcpdump-205.pcap, link-type EN10MB (Ethernet)
11:25:53.642732
11:25:53.653968

And related log extract:

"{\"timestamp\":\"2022-03-25T11:25:53.648153+0100\",\"flow_id\":296003109907151,\"in_iface\":\"ens36\",\"event_type\":\"alert\",\"src_ip\":\"47.244.154.186\",\"src_port\":5000,\"dest_ip\":\"100.106.140.66\",\"dest_port\":37466,\"proto\":\"TCP\",\"tx_id\":0,\"alert\":{\"action\":\"allowed\",\"gid\":1,\"signature_id\":7,\"rev\":0,\"signature\":\"\",\"category\":\"\",\"severity\":3},\"http\":{\"http_port\":0,\"url\":\"/libhtp::request_uri_not_seen\",\"http_content_type\":\"application/json\",\"status\":200,\"length\":111,\"http_response_body\":\"eyJyZXN1bHQiOnRydWUsIm1lc3NhZ2UiOiJ7XCJpbnN0cnVjdFwiOlwiXCIsXCJjb250ZW50XCI6XCJcIn0iLCJpc0Nvbm5lY3Rpb24iOmZhbHNlLCJzdGF0dXNDb2RlIjoyMDB9\"},\"files\":[{\"filename\":\"/libhtp::request_uri_not_seen\",\"sid\":[],\"gaps\":false,\"state\":\"CLOSED\",\"sha256\":\"1afe64585a50c19c48e4652826cbfdf7778f191571362f62ed0cdff0d5a93efd\",\"stored\":false,\"size\":102,\"tx_id\":0}],\"app_proto\":\"http\",\"flow\":{\"pkts_toserver\":4,\"pkts_toclient\":4,\"bytes_toserver\":739,\"bytes_toclient\":533,\"start\":\"2022-03-25T11:23:51.846543+0100\"},\"host\":\"katwork01-suricata\"}"
17

Hmm I tried to run your pcap but I can’t trigger the log part you posted. Can you share your pcap run with that you produced that log part?
I used the rules in your initial post.

18

You’re right. Sorry, I’ve attached wrong log line.
Here is the correct one:

"{\"timestamp\":\"2022-03-25T11:25:53.648153+0100\",\"flow_id\":296003109907151,\"in_iface\":\"ens36\",\"event_type\":\"alert\",\"src_ip\":\"47.244.154.186\",\"src_port\":5000,\"dest_ip\":\"100.106.140.66\",\"dest_port\":37466,\"proto\":\"TCP\",\"tx_id\":0,\"alert\":{\"action\":\"allowed\",\"gid\":1,\"signature_id\":7,\"rev\":0,\"signature\":\"\",\"category\":\"\",\"severity\":3},\"http\":{\"http_port\":0,\"url\":\"/libhtp::request_uri_not_seen\",\"http_content_type\":\"application/json\",\"status\":200,\"length\":111,\"http_response_body\":\"eyJyZXN1bHQiOnRydWUsIm1lc3NhZ2UiOiJ7XCJpbnN0cnVjdFwiOlwiXCIsXCJjb250ZW50XCI6XCJcIn0iLCJpc0Nvbm5lY3Rpb24iOmZhbHNlLCJzdGF0dXNDb2RlIjoyMDB9\"},\"files\":[{\"filename\":\"/libhtp::request_uri_not_seen\",\"sid\":[],\"gaps\":false,\"state\":\"CLOSED\",\"sha256\":\"1afe64585a50c19c48e4652826cbfdf7778f191571362f62ed0cdff0d5a93efd\",\"stored\":false,\"size\":102,\"tx_id\":0}],\"app_proto\":\"http\",\"flow\":{\"pkts_toserver\":4,\"pkts_toclient\":4,\"bytes_toserver\":739,\"bytes_toclient\":533,\"start\":\"2022-03-25T11:23:51.846543+0100\"},\"host\":\"katwork01-suricata\"}"
19

This is the same log file again?!

How did you compile/install Suricata?