Bug #3703
closedfileinfo "stored: false" even if the file is kept on disk
Description
Hi,
We believe we found a reproducible bug in the file store code.
Basically, what happens is that some streams contain files that are correctly extracted, dumped on disk, marked as closed (not truncated), and moved from tmp/ to the filestore while the fileinfo eve-log indicates that the file was not stored. We have been observing this for a while now, and were recently able to reproduce it in lab, on Suricata 4.1.8 and Suricata 5.0.3.
This is problematic, especially if one is doing automated analysis of the extracted files and not using `write-fileinfo: yes`, because it means that the file might remain "unknown" and never be automatically analyzed.
The suricata config is nothing fancy; we kept the default config from the Ubuntu package, with file-store v2 enabled, and a very basic filemagic rule:
```
alert http any any -> any any (msg: "FILEMAGIC PDF document"; filemagic:"PDF document"; filestore:both,file; noalert; sid:1100008; rev:1;)
```
The bug can be reproduced with the attached pcap file. This is not an isolated case; we were able to reproduce it with several other streams that have similar flow profile. Specifically, after the initial handshake, the file is pushed in its entirety, without any acknowledgment, then all acknowledgment segments are sent and the connection is closed abruptly with a RST. While this way of doing TCP is dirty efficient, it remains valid.
Please reach out to us if you need any more details regarding this issue.
Thank you.
Florian Maury for ArmatureTech DevTeam
Files
Related issues
Updated by Armature Technologies 7 months ago
Hi,
Just an quick update from our side: we have been able to confirm that the issue is still present in the latest stable version of Suricata (6.0.1 at the time of writing). The fileinfo event continues to indicate that the file was not stored even though it effectively was stored.
We have heard feedback from production networks where these false reports represent north of 25% of files stored by Suricata. This problem is significant and we are a bit abashed that this bug report has remained unanswered and unaddressed, as accuracy is probably one of the most desirable attributes of an IDS.
We have not been able to come-up with a fix of our own for this issue, and help would be very much appreciated.
Thank you.
Cheers,
Florian Maury
Updated by Victor Julien 7 months ago
- Status changed from New to Assigned
- Assignee set to Jeff Lucovsky
- Target version set to 7.0rc1
- Label Needs backport to 5.0, Needs backport to 6.0 added
Updated by Jeff Lucovsky 7 months ago
- Status changed from Assigned to In Progress
Removed errant post.
I was able to reproduce the issue -- sorry for the confusion.
Updated by Jeff Lucovsky 7 months ago
- Copied to Bug #4382: fileinfo "stored: false" even if the file is kept on disk added
Updated by Jeff Lucovsky 7 months ago
- Copied to Bug #4383: fileinfo "stored: false" even if the file is kept on disk added
Updated by Armature Technologies 6 months ago
- File reproduction.tgz reproduction.tgz added
Hi,
Thank you for trying to reproduce the bug.
It is really weird that you cannot; it might be related to some config options that you have activated.
The attached archive contains a Dockerfile and all of the resources necessary to reproduce the bug. The dockerfile checks out from github, and builds from source. The config file is the one provided by the Debian package on the OISF PPA, with filestore enabled and the paths modified to make it work.
You can just run the following commands:
```
podman build -t suricata5 --build-arg SURIBRANCH=master-5.0.x .
podman run suricata5
podman build -t suricata6 --build-arg SURIBRANCH=master-6.0.x .
podman run suricata6
```
I get the following output:
```
8/3/2021 -- 11:16:07 - <Notice> - This is Suricata version 5.0.6 RELEASE running in USER mode
8/3/2021 -- 11:16:07 - <Notice> - JsonRdpLog logger not enabled: protocol rdp is disabled
8/3/2021 -- 11:16:07 - <Warning> - [ERRCODE: SC_ERR_INVALID_ARGUMENT(13)] - No output module named eve-log.dcerpc
8/3/2021 -- 11:16:07 - <Warning> - [ERRCODE: SC_ERR_INVALID_ARGUMENT(13)] - No output module named eve-log.rfb
8/3/2021 -- 11:16:07 - <Notice> - JsonSIPLog logger not enabled: protocol sip is disabled
8/3/2021 -- 11:16:07 - <Warning> - [ERRCODE: SC_ERR_INVALID_ARGUMENT(13)] - No output module named eve-log.mqtt
8/3/2021 -- 11:16:07 - <Notice> - all 13 packet processing threads, 4 management threads initialized, engine started.
8/3/2021 -- 11:16:07 - <Notice> - Signal Received. Stopping engine.
8/3/2021 -- 11:16:07 - <Notice> - Pcap-file module read 1 files, 22 packets, 11749 bytes
{
"timestamp": "2019-09-30T09:16:05.585275+0000",
"flow_id": 1029515603471061,
"pcap_cnt": 17,
"event_type": "fileinfo",
"src_ip": "192.168.0.2",
"src_port": 80,
"dest_ip": "192.168.0.1",
"dest_port": 36656,
"proto": "TCP",
"http": {
"hostname": "192.168.0.2",
"url": "/467659.pdf",
"http_content_type": "application/pdf",
"http_method": "GET",
"protocol": "HTTP/1.1",
"status": 200,
"length": 9952
},
"app_proto": "http",
"fileinfo": {
"filename": "/467659.pdf",
"sid": [],
"gaps": false,
"state": "CLOSED",
"sha256": "02f43016d07812f881dc1ccee724f95682016ff00c7ee6b2c856d4d693ce3fa5",
"stored": false,
"size": 9952,
"tx_id": 0
}
}
12324026 12 rw-r--r- 1 root root 9952 Mar 8 11:16 filestore/02/02f43016d07812f881dc1ccee724f95682016ff00c7ee6b2c856d4d693ce3fa5
```
As you can see, I have a file in the filestore but the fileinfo states `"stored": false`
Please let us know if you manage to reproduce the issue with the provided dockerfile.
Thank you.
Cheers,
Florian Maury
Updated by Victor Julien 6 months ago
- Assignee changed from Jeff Lucovsky to Victor Julien
Work in progress here https://github.com/OISF/suricata/pull/5999
Updated by Armature Technologies 4 months ago
Hi,
We would like to thank you for the work that has been done regarding this issue. It seems like the source cause has been a real pain to tackle, but that you have made good progress.
We would like to know if there is any chance for the linked PR to be merged in the near future. Are there any roadblocks that we are missing to see preventing the PR from being merged? And if so, could you please provide instructions to help you merge this PR?
Thank you.
Regards,
Florian Maury
Updated by Victor Julien 3 days ago
- Status changed from In Progress to Closed