Suricata

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.