Project

General

Profile

Bug #2490

Filehash rule does not fire without filestore keyword

Added by Antti Tönkyrä over 1 year ago. Updated about 16 hours ago.

Status:
Feedback
Priority:
Normal
Assignee:
Target version:
Affected Versions:
Effort:
Difficulty:
Label:

Description

I was testing some filehash rules and encountered an issue where suricata alert does not fire without filestore keyword. The hash is logged and from the looks of it loaded as normal even without the keyword but alert never fires.

First run without the filestore keyword.

$ echo 'e19c1283c925b3206685ff522acfe3e6' > ../rules/target.md5
$ echo 'alert http any any -> any any (msg:"test"; filemd5: target.md5; classtype: bad-unknown; sid:1530024;)' > ../rules/target.rules
$ rm ../logs/*
$ ./suricata -c ../suricata.yaml -vr target.pcap; cat ../logs/eve.json 
Error opening file /usr/local/var/log/suricata/suricata.log
[23228] 16/4/2018 -- 13:55:46 - (suricata.c:1076) <Notice> (LogVersion) -- This is Suricata version 4.1.0-dev (rev 2e8fd612)
[23228] 16/4/2018 -- 13:55:46 - (util-cpu.c:171) <Info> (UtilCpuPrintSummary) -- CPUs/cores online: 4
[23228] 16/4/2018 -- 13:55:46 - (util-logopenfile.c:501) <Info> (SCConfLogOpenGeneric) -- fast output device (regular) initialized: fast.log
[23228] 16/4/2018 -- 13:55:46 - (util-logopenfile.c:501) <Info> (SCConfLogOpenGeneric) -- eve-log output device (regular) initialized: eve.json
[23228] 16/4/2018 -- 13:55:46 - (util-logopenfile.c:501) <Info> (SCConfLogOpenGeneric) -- stats output device (regular) initialized: stats.log
[23228] 16/4/2018 -- 13:55:46 - (detect-file-hash-common.c:270) <Info> (DetectFileHashParse) -- Hash hash table size 2097200 bytes
[23228] 16/4/2018 -- 13:55:46 - (detect-engine-loader.c:351) <Info> (SigLoadSignatures) -- 1 rule files processed. 1 rules successfully loaded, 0 rules failed
[23228] 16/4/2018 -- 13:55:46 - (util-threshold-config.c:248) <Warning> (SCThresholdConfInitContext) -- [ERRCODE: SC_ERR_FOPEN(44)] - Error opening file: "/usr/local/etc/suricata//threshold.config": No such file or directory
[23228] 16/4/2018 -- 13:55:46 - (detect-engine-build.c:1398) <Info> (SigAddressPrepareStage1) -- 1 signatures processed. 0 are IP-only rules, 0 are inspecting packet payload, 1 inspect application layer, 0 are decoder event only
[23242] 16/4/2018 -- 13:55:46 - (source-pcap-file.c:235) <Info> (ReceivePcapFileThreadInit) -- Checking file or directory target.pcap
[23242] 16/4/2018 -- 13:55:46 - (source-pcap-file-directory-helper.c:212) <Info> (PcapDetermineDirectoryOrFile) -- target.pcap: Plain file, not a directory
[23242] 16/4/2018 -- 13:55:46 - (source-pcap-file.c:243) <Info> (ReceivePcapFileThreadInit) -- Argument target.pcap was a file
[23228] 16/4/2018 -- 13:55:46 - (tm-threads.c:2172) <Notice> (TmThreadWaitOnThreadInit) -- all 5 packet processing threads, 4 management threads initialized, engine started.
[23242] 16/4/2018 -- 13:55:46 - (source-pcap-file.c:167) <Info> (ReceivePcapFileLoop) -- Starting file run for target.pcap
[23242] 16/4/2018 -- 13:55:46 - (source-pcap-file-helper.c:142) <Info> (PcapFileDispatch) -- pcap file target.pcap end of file reached (pcap err code 0)
[23228] 16/4/2018 -- 13:55:46 - (suricata.c:2733) <Notice> (SuricataMainLoop) -- Signal Received.  Stopping engine.
[23228] 16/4/2018 -- 13:55:46 - (suricata.c:1100) <Info> (SCPrintElapsedTime) -- time elapsed 0.027s
[23242] 16/4/2018 -- 13:55:46 - (source-pcap-file.c:377) <Notice> (ReceivePcapFileThreadExitStats) -- Pcap-file module read 1 files, 9 packets, 1041 bytes
[23228] 16/4/2018 -- 13:55:46 - (counters.c:815) <Info> (StatsLogSummary) -- Alerts: 0
[23228] 16/4/2018 -- 13:55:46 - (detect-engine-build.c:1704) <Info> (SigAddressCleanupStage1) -- cleaning up signature grouping structure... complete
{"timestamp":"2018-04-16T13:00:19.215366+0300","flow_id":2233423598160318,"pcap_cnt":6,"event_type":"http","src_ip":"10.220.109.46","src_port":41160,"dest_ip":"87.108.18.34","dest_port":80,"proto":"TCP","tx_id":0,"http":{"hostname":"d.adm.fi","url":"\/test","http_user_agent":"curl\/7.59.0","http_content_type":"text\/plain","http_method":"GET","protocol":"HTTP\/1.1","status":200,"length":15}}
{"timestamp":"2018-04-16T13:00:19.215366+0300","flow_id":2233423598160318,"pcap_cnt":6,"event_type":"fileinfo","src_ip":"10.220.109.46","src_port":41160,"dest_ip":"87.108.18.34","dest_port":80,"proto":"TCP","http":{"hostname":"d.adm.fi","url":"\/test","http_user_agent":"curl\/7.59.0","http_content_type":"text\/plain","http_method":"GET","protocol":"HTTP\/1.1","status":200,"length":15},"app_proto":"http","fileinfo":{"filename":"\/test","gaps":false,"state":"CLOSED","md5":"e19c1283c925b3206685ff522acfe3e6","stored":false,"size":15,"tx_id":0}}
{"timestamp":"2018-04-16T13:00:19.235943+0300","flow_id":2233423598160318,"event_type":"flow","src_ip":"10.220.109.46","src_port":41160,"dest_ip":"87.108.18.34","dest_port":80,"proto":"TCP","app_proto":"http","flow":{"pkts_toserver":6,"pkts_toclient":3,"bytes_toserver":480,"bytes_toclient":561,"start":"2018-04-16T13:00:19.166334+0300","end":"2018-04-16T13:00:19.235943+0300","age":0,"state":"closed","reason":"shutdown","alerted":false},"tcp":{"tcp_flags":"1b","tcp_flags_ts":"1b","tcp_flags_tc":"1b","syn":true,"fin":true,"psh":true,"ack":true,"state":"closed"}}

Second run with the filestore keyword

{"timestamp":"2018-04-16T13:00:19.215366+0300","flow_id":512623476181438,"pcap_cnt":6,"event_type":"http","src_ip":"10.220.109.46","src_port":41160,"dest_ip":"87.108.18.34","dest_port":80,"proto":"TCP","tx_id":0,"http":{"hostname":"d.adm.fi","url":"\/test","http_user_agent":"curl\/7.59.0","http_content_type":"text\/plain","http_method":"GET","protocol":"HTTP\/1.1","status":200,"length":15}}
{"timestamp":"2018-04-16T13:00:19.215366+0300","flow_id":512623476181438,"pcap_cnt":6,"event_type":"fileinfo","src_ip":"10.220.109.46","src_port":41160,"dest_ip":"87.108.18.34","dest_port":80,"proto":"TCP","http":{"hostname":"d.adm.fi","url":"\/test","http_user_agent":"curl\/7.59.0","http_content_type":"text\/plain","http_method":"GET","protocol":"HTTP\/1.1","status":200,"length":15},"app_proto":"http","fileinfo":{"filename":"\/test","gaps":false,"state":"CLOSED","md5":"e19c1283c925b3206685ff522acfe3e6","stored":false,"size":15,"tx_id":0}}
{"timestamp":"2018-04-16T13:00:19.235864+0300","flow_id":512623476181438,"pcap_cnt":8,"event_type":"alert","src_ip":"87.108.18.34","src_port":80,"dest_ip":"10.220.109.46","dest_port":41160,"proto":"TCP","tx_id":0,"alert":{"action":"allowed","gid":1,"signature_id":1530024,"rev":0,"signature":"test","category":"Potentially Bad Traffic","severity":2},"http":{"hostname":"d.adm.fi","url":"\/test","http_user_agent":"curl\/7.59.0","http_content_type":"text\/plain","http_method":"GET","protocol":"HTTP\/1.1","status":200,"length":15},"app_proto":"http","flow":{"pkts_toserver":5,"pkts_toclient":3,"bytes_toserver":414,"bytes_toclient":561,"start":"2018-04-16T13:00:19.166334+0300"}}
{"timestamp":"2018-04-16T13:00:19.235943+0300","flow_id":512623476181438,"event_type":"flow","src_ip":"10.220.109.46","src_port":41160,"dest_ip":"87.108.18.34","dest_port":80,"proto":"TCP","app_proto":"http","flow":{"pkts_toserver":6,"pkts_toclient":3,"bytes_toserver":480,"bytes_toclient":561,"start":"2018-04-16T13:00:19.166334+0300","end":"2018-04-16T13:00:19.235943+0300","age":0,"state":"closed","reason":"shutdown","alerted":true},"tcp":{"tcp_flags":"1b","tcp_flags_ts":"1b","tcp_flags_tc":"1b","syn":true,"fin":true,"psh":true,"ack":true,"state":"closed"}}

As you can see, the filestore rule fires as one would expect. Both have the correct MD5sum for the file in EVE-json. I have attached the pcap file I used to test the issue.

Exact suricata commit used in testing is 2e8fd612a63902829a3c518729fbc07c26ce92a1.


Files

target.pcap (1.18 KB) target.pcap pcap used to test the issue Antti Tönkyrä, 04/16/2018 11:00 AM
testcase.tgz (3.29 KB) testcase.tgz Antti Tönkyrä, 07/10/2019 11:26 PM

History

#1

Updated by Antti Tönkyrä over 1 year ago

Oops, missed the actual commands leading to the with-filestore execution:

$ echo 'e19c1283c925b3206685ff522acfe3e6' > ../rules/target.md5
$ echo 'alert http any any -> any any (msg:"test"; filemd5: target.md5; filestore; classtype: bad-unknown; sid:1530024;)' > ../rules/target.rules
$ rm ../logs/*; ./suricata -c ../suricata.yaml -vr target.pcap; cat ../logs/eve.json 
Error opening file /usr/local/var/log/suricata/suricata.log
[24671] 16/4/2018 -- 13:57:33 - (suricata.c:1076) <Notice> (LogVersion) -- This is Suricata version 4.1.0-dev (rev 2e8fd612)
[24671] 16/4/2018 -- 13:57:33 - (util-cpu.c:171) <Info> (UtilCpuPrintSummary) -- CPUs/cores online: 4
[24671] 16/4/2018 -- 13:57:33 - (util-logopenfile.c:501) <Info> (SCConfLogOpenGeneric) -- fast output device (regular) initialized: fast.log
[24671] 16/4/2018 -- 13:57:33 - (util-logopenfile.c:501) <Info> (SCConfLogOpenGeneric) -- eve-log output device (regular) initialized: eve.json
[24671] 16/4/2018 -- 13:57:33 - (util-logopenfile.c:501) <Info> (SCConfLogOpenGeneric) -- stats output device (regular) initialized: stats.log
[24671] 16/4/2018 -- 13:57:33 - (detect-file-hash-common.c:270) <Info> (DetectFileHashParse) -- Hash hash table size 2097200 bytes
[24671] 16/4/2018 -- 13:57:33 - (detect-engine-loader.c:351) <Info> (SigLoadSignatures) -- 1 rule files processed. 1 rules successfully loaded, 0 rules failed
[24671] 16/4/2018 -- 13:57:33 - (util-threshold-config.c:248) <Warning> (SCThresholdConfInitContext) -- [ERRCODE: SC_ERR_FOPEN(44)] - Error opening file: "/usr/local/etc/suricata//threshold.config": No such file or directory
[24671] 16/4/2018 -- 13:57:33 - (detect-engine-build.c:1398) <Info> (SigAddressPrepareStage1) -- 1 signatures processed. 0 are IP-only rules, 0 are inspecting packet payload, 1 inspect application layer, 0 are decoder event only
[24686] 16/4/2018 -- 13:57:33 - (source-pcap-file.c:235) <Info> (ReceivePcapFileThreadInit) -- Checking file or directory target.pcap
[24686] 16/4/2018 -- 13:57:33 - (source-pcap-file-directory-helper.c:212) <Info> (PcapDetermineDirectoryOrFile) -- target.pcap: Plain file, not a directory
[24686] 16/4/2018 -- 13:57:33 - (source-pcap-file.c:243) <Info> (ReceivePcapFileThreadInit) -- Argument target.pcap was a file
[24671] 16/4/2018 -- 13:57:33 - (tm-threads.c:2172) <Notice> (TmThreadWaitOnThreadInit) -- all 5 packet processing threads, 4 management threads initialized, engine started.
[24686] 16/4/2018 -- 13:57:33 - (source-pcap-file.c:167) <Info> (ReceivePcapFileLoop) -- Starting file run for target.pcap
[24686] 16/4/2018 -- 13:57:33 - (source-pcap-file-helper.c:142) <Info> (PcapFileDispatch) -- pcap file target.pcap end of file reached (pcap err code 0)
[24671] 16/4/2018 -- 13:57:33 - (suricata.c:2733) <Notice> (SuricataMainLoop) -- Signal Received.  Stopping engine.
[24671] 16/4/2018 -- 13:57:33 - (suricata.c:1100) <Info> (SCPrintElapsedTime) -- time elapsed 0.027s
[24686] 16/4/2018 -- 13:57:33 - (source-pcap-file.c:377) <Notice> (ReceivePcapFileThreadExitStats) -- Pcap-file module read 1 files, 9 packets, 1041 bytes
[24671] 16/4/2018 -- 13:57:33 - (counters.c:815) <Info> (StatsLogSummary) -- Alerts: 1
[24671] 16/4/2018 -- 13:57:33 - (detect-engine-build.c:1704) <Info> (SigAddressCleanupStage1) -- cleaning up signature grouping structure... complete
{"timestamp":"2018-04-16T13:00:19.215366+0300","flow_id":512623476181438,"pcap_cnt":6,"event_type":"http","src_ip":"10.220.109.46","src_port":41160,"dest_ip":"87.108.18.34","dest_port":80,"proto":"TCP","tx_id":0,"http":{"hostname":"d.adm.fi","url":"\/test","http_user_agent":"curl\/7.59.0","http_content_type":"text\/plain","http_method":"GET","protocol":"HTTP\/1.1","status":200,"length":15}}
{"timestamp":"2018-04-16T13:00:19.215366+0300","flow_id":512623476181438,"pcap_cnt":6,"event_type":"fileinfo","src_ip":"10.220.109.46","src_port":41160,"dest_ip":"87.108.18.34","dest_port":80,"proto":"TCP","http":{"hostname":"d.adm.fi","url":"\/test","http_user_agent":"curl\/7.59.0","http_content_type":"text\/plain","http_method":"GET","protocol":"HTTP\/1.1","status":200,"length":15},"app_proto":"http","fileinfo":{"filename":"\/test","gaps":false,"state":"CLOSED","md5":"e19c1283c925b3206685ff522acfe3e6","stored":false,"size":15,"tx_id":0}}
{"timestamp":"2018-04-16T13:00:19.235864+0300","flow_id":512623476181438,"pcap_cnt":8,"event_type":"alert","src_ip":"87.108.18.34","src_port":80,"dest_ip":"10.220.109.46","dest_port":41160,"proto":"TCP","tx_id":0,"alert":{"action":"allowed","gid":1,"signature_id":1530024,"rev":0,"signature":"test","category":"Potentially Bad Traffic","severity":2},"http":{"hostname":"d.adm.fi","url":"\/test","http_user_agent":"curl\/7.59.0","http_content_type":"text\/plain","http_method":"GET","protocol":"HTTP\/1.1","status":200,"length":15},"app_proto":"http","flow":{"pkts_toserver":5,"pkts_toclient":3,"bytes_toserver":414,"bytes_toclient":561,"start":"2018-04-16T13:00:19.166334+0300"}}
{"timestamp":"2018-04-16T13:00:19.235943+0300","flow_id":512623476181438,"event_type":"flow","src_ip":"10.220.109.46","src_port":41160,"dest_ip":"87.108.18.34","dest_port":80,"proto":"TCP","app_proto":"http","flow":{"pkts_toserver":6,"pkts_toclient":3,"bytes_toserver":480,"bytes_toclient":561,"start":"2018-04-16T13:00:19.166334+0300","end":"2018-04-16T13:00:19.235943+0300","age":0,"state":"closed","reason":"shutdown","alerted":true},"tcp":{"tcp_flags":"1b","tcp_flags_ts":"1b","tcp_flags_tc":"1b","syn":true,"fin":true,"psh":true,"ack":true,"state":"closed"}}

#2

Updated by Andreas Herz about 1 year ago

  • Assignee set to OISF Dev
  • Target version set to TBD
#3

Updated by Andreas Herz 10 days ago

  • Status changed from New to Feedback

what does your suricata.yaml look like?

#4

Updated by Antti Tönkyrä 10 days ago

Thanks for looking at this, I re-tested this and looks like problem is present in at least in 4.0.4. I can try to test 4.1.4 later too.

I can produce following results:

The following cases will trigger an alert:
  • Suricata with files enabled on eve-log, filestore in rule
  • Suricata with files enabled on eve-log, NO filestore in rule
  • Suricata with NO files enabled on eve-log, filestore in rule
The following cases will NOT trigger an alert
  • Suricata with NO files enabled on eve-log, NO filestore in rule

So, to summarize, alerts get triggered with these commandlines (looking at fast.log)

suricata -c suricata-noevefile.yaml -r target.pcap -S rules/target-filestore.rules
suricata -c suricata-evefile.yaml -r target.pcap -S rules/target-filestore.rules
suricata -c suricata-evefile.yaml -r target.pcap -S rules/target.rules

And I would expect an alert with this command too, but none are generated in fast.log

suricata -c suricata-noevefile.yaml -r target.pcap -S rules/target.rules

I have attached necessary files in a tarball which can be used to reproduce the commands above.

#5

Updated by Antti Tönkyrä 10 days ago

  • Affected Versions 4.1.4 added
  • Affected Versions deleted (4.0.4)

Okay verified the same behavior on freshly compiled 4.1.4 too.

#6

Updated by Andreas Herz about 16 hours ago

Thanks for the details, that's something that needs to fixed or either documented if it's intended behaviour.

Also available in: Atom PDF