[Oisf-devel] File MD5 inconsistent checksums.

Victor Julien victor at inliniac.net
Thu Jul 12 08:11:56 UTC 2012


On 07/12/2012 10:09 AM, Nikolay Denev wrote:
> 
> On Jul 12, 2012, at 10:16 AM, Victor Julien wrote:
> 
>> On 07/12/2012 08:27 AM, Nikolay Denev wrote:
>>>
>>> On Jul 12, 2012, at 9:25 AM, Nikolay Denev wrote:
>>>
>>>> On Jul 12, 2012, at 9:03 AM, Nikolay Denev wrote:
>>>>
>>>>> Hi,
>>>>>
>>>>> I'm seeing some strange behaviour while testing the filemd5 and md5 checksumming in general.
>>>>>
>>>>> I have a server which serves a file over http and the server port on the switch is mirrored to a box running suricata.
>>>>>
>>>>> I have the md5 of the file as it is on the server : c2ddef96c8a1aeddf316ff3cba37f318
>>>>> When I do a curl download and pipe it to md5 the checksum matches.
>>>>>
>>>>> :~ ndenev$ curl http://testserver.example.com/test.img | md5
>>>>> % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
>>>>>                               Dload  Upload   Total   Spent    Left  Speed
>>>>> 100  117k  100  117k    0     0  1744k      0 --:--:-- --:--:-- --:--:-- 1933k
>>>>> c2ddef96c8a1aeddf316ff3cba37f318
>>>>>
>>>>> However the filemd5 rule I've created never matches, and files-json.log shows completely different checksums, which also are not consistent?
>>>>> And the filesize too differs, and as I said the curl on the client machine gives the same md5 each time.
>>>>>
>>>>> { "timestamp": "07\/12\/2012-07:56:15.944637", "ipver": 4, "srcip": "10.128.2.35", "dstip": "10.46.16.9", "protocol": 6, "sp": 80, "dp": 51135, "http_uri": "\/test.img", "http_host": "testserver.example.com", "http_referer": "<unknown>", "filename": "\/test.img", "magic": "ASCII text", "state": "CLOSED", "md5": "7890dc88c2f0f4d0706eef8bbfc33d75", "stored": false, "size": 4152 }
>>>>> { "timestamp": "07\/12\/2012-07:56:25.033265", "ipver": 4, "srcip": "10.128.2.35", "dstip": "10.46.16.9", "protocol": 6, "sp": 80, "dp": 51136, "http_uri": "\/test.img", "http_host": "testserver.example.com", "http_referer": "<unknown>", "filename": "\/test.img", "magic": "ASCII text", "state": "CLOSED", "md5": "4b9fda98fbee8f4afea75b7b466b2e1a", "stored": false, "size": 3839 }
>>>>> { "timestamp": "07\/12\/2012-07:56:30.232624", "ipver": 4, "srcip": "10.128.2.35", "dstip": "10.46.16.9", "protocol": 6, "sp": 80, "dp": 51138, "http_uri": "\/test.img", "http_host": "testserver.example.com", "http_referer": "<unknown>", "filename": "\/test.img", "magic": "ASCII text", "state": "CLOSED", "md5": "7890dc88c2f0f4d0706eef8bbfc33d75", "stored": false, "size": 4152 }
>>>>> { "timestamp": "07\/12\/2012-07:56:35.410789", "ipver": 4, "srcip": "10.128.2.35", "dstip": "10.46.16.9", "protocol": 6, "sp": 80, "dp": 51140, "http_uri": "\/test.img", "http_host": "testserver.example.com", "http_referer": "<unknown>", "filename": "\/test.img", "magic": "ASCII text", "state": "CLOSED", "md5": "7890dc88c2f0f4d0706eef8bbfc33d75", "stored": false, "size": 4152 }
>>>>> { "timestamp": "07\/12\/2012-07:56:39.225699", "ipver": 4, "srcip": "10.128.2.35", "dstip": "10.46.16.9", "protocol": 6, "sp": 80, "dp": 51142, "http_uri": "\/test.img", "http_host": "testserver.example.com", "http_referer": "<unknown>", "filename": "\/test.img", "magic": "ASCII text", "state": "CLOSED", "md5": "7890dc88c2f0f4d0706eef8bbfc33d75", "stored": false, "size": 4152 }
>>>>>
>>>>>
>>>>> This is the latest entry in my stats.log :
>>>>>
>>>>> -------------------------------------------------------------------
>>>>> Date: 7/12/2012 -- 08:00:24 (uptime: 0d, 00h 11m 20s)
>>>>> -------------------------------------------------------------------
>>>>> Counter                   | TM Name                   | Value
>>>>> -------------------------------------------------------------------
>>>>> tcp.sessions              | Detect                    | 11097
>>>>> tcp.ssn_memcap_drop       | Detect                    | 0
>>>>> tcp.pseudo                | Detect                    | 6762
>>>>> tcp.invalid_checksum      | Detect                    | 22
>>>>> tcp.no_flow               | Detect                    | 0
>>>>> tcp.reused_ssn            | Detect                    | 0
>>>>> tcp.memuse                | Detect                    | 72351744
>>>>> tcp.syn                   | Detect                    | 11520
>>>>> tcp.synack                | Detect                    | 10973
>>>>> tcp.rst                   | Detect                    | 7998
>>>>> tcp.segment_memcap_drop   | Detect                    | 0
>>>>> tcp.stream_depth_reached  | Detect                    | 0
>>>>> tcp.reassembly_memuse     | Detect                    | 156557860
>>>>> tcp.reassembly_gap        | Detect                    | 3646
>>>>> detect.alert              | Detect                    | 24
>>>>> decoder.pkts              | RxPcapix01                | 7799419
>>>>> decoder.bytes             | RxPcapix01                | 6619532090
>>>>> decoder.ipv4              | RxPcapix01                | 7732780
>>>>> decoder.ipv6              | RxPcapix01                | 181
>>>>> decoder.ethernet          | RxPcapix01                | 7799419
>>>>> decoder.raw               | RxPcapix01                | 0
>>>>> decoder.sll               | RxPcapix01                | 0
>>>>> decoder.tcp               | RxPcapix01                | 4036503
>>>>> decoder.udp               | RxPcapix01                | 767312
>>>>> decoder.sctp              | RxPcapix01                | 0
>>>>> decoder.icmpv4            | RxPcapix01                | 1957
>>>>> decoder.icmpv6            | RxPcapix01                | 0
>>>>> decoder.ppp               | RxPcapix01                | 0
>>>>> decoder.pppoe             | RxPcapix01                | 0
>>>>> decoder.gre               | RxPcapix01                | 0
>>>>> decoder.vlan              | RxPcapix01                | 15588470
>>>>> decoder.avg_pkt_size      | RxPcapix01                | 849
>>>>> decoder.max_pkt_size      | RxPcapix01                | 1518
>>>>> defrag.ipv4.fragments     | RxPcapix01                | 0
>>>>> defrag.ipv4.reassembled   | RxPcapix01                | 0
>>>>> defrag.ipv4.timeouts      | RxPcapix01                | 0
>>>>> defrag.ipv6.fragments     | RxPcapix01                | 0
>>>>> defrag.ipv6.reassembled   | RxPcapix01                | 0
>>>>> defrag.ipv6.timeouts      | RxPcapix01                | 0
>>>>> flow_mgr.closed_pruned    | FlowManagerThread         | 9036
>>>>> flow_mgr.new_pruned       | FlowManagerThread         | 3033
>>>>> flow_mgr.est_pruned       | FlowManagerThread         | 4478
>>>>> flow.memuse               | FlowManagerThread         | 5401024
>>>>> flow.spare                | FlowManagerThread         | 10034
>>>>> flow.emerg_mode_entered   | FlowManagerThread         | 0
>>>>> flow.emerg_mode_over      | FlowManagerThread         | 0
>>>>
>>>> I've now setup a rule to "filestore" the downloads so I can check them, and the stored files seem truncated.
>>>>
>>>> Also files-json.log continues to log "stored: false" while the files are actually saved.
>>>>
>>>>
>>>
>>> The file on the server is about 120K, but the saved files are about 4K.
>>> Which also reminds me that I've never actually saw a file much bigger than a few KBs in my files dir.
>>
>> Did you try increasing your request-body-limit and response-body-limit?
>> https://redmine.openinfosecfoundation.org/projects/suricata/wiki/File_Extraction#Settings
>>
>> The fact that the state is "closed" looks like a bug btw.
>>
>> -- 
>> ---------------------------------------------
>> Victor Julien
>> http://www.inliniac.net/
>> PGP: http://www.inliniac.net/victorjulien.asc
>> ---------------------------------------------
>>
> 
> My request-body-limit was set to 0 (unlimited), and response-body-limit was about 3k, and I've set it now to unlimited too.
> Also my stream.reassembly.depth is set to unlimited.
> 
> Now I'm seeing this in files-json.log :
> 
> { "id": 95268539, "timestamp": "07\/12\/2012-10:01:40.012440", "ipver": 4, "srcip": "10.128.2.35", "dstip": "10.129.23.105", "protocol": 6, "sp": 80, "dp": 53072, "http_uri": "\/test.img", "http_host": "testserver.example.com", "http_referer": "<unknown>", "filename": "\/test.img", "magic": "ASCII text", "state": "UNKNOWN", "stored": true, "size": 88654 }
> { "id": 95268540, "timestamp": "07\/12\/2012-10:01:56.041302", "ipver": 4, "srcip": "10.128.2.35", "dstip": "10.129.23.105", "protocol": 6, "sp": 80, "dp": 53074, "http_uri": "\/test.img", "http_host": "testserver.example.com", "http_referer": "<unknown>", "filename": "\/test.img", "magic": "ASCII text", "state": "UNKNOWN", "stored": true, "size": 88654 }
> { "id": 95268541, "timestamp": "07\/12\/2012-10:01:59.306984", "ipver": 4, "srcip": "10.128.2.35", "dstip": "10.129.23.105", "protocol": 6, "sp": 80, "dp": 53076, "http_uri": "\/test.img", "http_host": "testserver.example.com", "http_referer": "<unknown>", "filename": "\/test.img", "magic": "ASCII text", "state": "UNKNOWN", "stored": true, "size": 88654 }
> 
> No MD5, but it says "stored:true".
> The file is much bigger, but again truncated.
> 
> 
> I can provide my suricata.yaml if needed.
> 

Cool. A pcap would also be good.

Btw, I noticed in your stats.log that you have quite a few
tcp.reassembly_gap's. Might indicate pkt loss or stream engine running
low on memory.

-- 
---------------------------------------------
Victor Julien
http://www.inliniac.net/
PGP: http://www.inliniac.net/victorjulien.asc
---------------------------------------------






More information about the Oisf-devel mailing list