Project

General

Profile

Actions

Bug #5811

closed

smb: tx logs sometimes have duplicate `tree_id` output

Added by Andreas Herz almost 2 years ago. Updated almost 2 years ago.

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

Description

We have those events even for some suricata-verify tests, so should be easy to reproduce and debug, see for example:

smb-named-pipe-unicode/output/eve.json:{"timestamp":"2020-04-14T16:45:34.732215+0000","flow_id":1855357390218608,"pcap_cnt":14,"event_type":"alert","src_ip":"192.168.1.100","src_port":41688,"dest_ip":"192.168.1.3","dest_port":445,"proto":"TCP","pkt_src":"wire/pcap","tx_id":3,"alert":{"action":"allowed","gid":1,"signature_id":1,"rev":1,"signature":"Ascii named_pipe","category":"","severity":3},"smb":{"id":4,"dialect":"NT LM 0.12","command":"SMB1_COMMAND_TREE_CONNECT_ANDX","status":"STATUS_SUCCESS","status_code":"0x0","session_id":4096,"tree_id":2052,"tree_id":2052,"named_pipe":"\\192.168.1.3\\IPC$","service":{"request":"?????","response":"IPC"}},"app_proto":"smb","direction":"to_server","flow":{"pkts_toserver":8,"pkts_toclient":6,"bytes_toserver":1132,"bytes_toclient":1245,"start":"2020-04-14T16:45:34.694128+0000","src_ip":"192.168.1.100","dest_ip":"192.168.1.3","src_port":41688,"dest_port":445}}

Related issues 1 (0 open1 closed)

Related to Suricata - Bug #5933: smb: tx logs sometimes have duplicate `tree_id` output (6.0.x backport)ClosedJason IshActions
Actions #2

Updated by Andreas Herz almost 2 years ago

The reason for that is, that in `rust/src/smb.log.rs` we have an additional entry that is print in addition:

        Some(SMBTransactionTypeData::TREECONNECT(ref x)) => {
            jsb.set_uint("tree_id", x.tree_id as u64)?;

While the generic one that is printed everytime is `tx.hdr.tree_id` this one is `x.tree_id` but based on the testruns it's always the same as the `hdr` one. So it might just be not needed at all or the stored value is wrong.

Actions #3

Updated by Jason Ish almost 2 years ago

Andreas Herz wrote in #note-2:

The reason for that is, that in `rust/src/smb.log.rs` we have an additional entry that is print in addition:
[...]

While the generic one that is printed everytime is `tx.hdr.tree_id` this one is `x.tree_id` but based on the testruns it's always the same as the `hdr` one. So it might just be not needed at all or the stored value is wrong.

Thats my assumption as well. The `tree_id` is being "hoisted" up into the common header, cause if you look at the PCAP for a TREECONNECT, the Tree ID does exist only once, however our data structures suggest otherwise. My guess is that removing this line is the fix. Thoughts @Victor Julien ?

Actions #4

Updated by Andreas Herz almost 2 years ago

In addition to that I would also check if we read the correct tree_id.

In `smb-named-pipe-ascii-frames` we have the following event:

{"timestamp":"2020-03-10T18:22:46.113634+0000","flow_id":1704892135654207,"pcap_cnt":14,"event_type":"alert","src_ip":"192.168.1.100","src_port":55768,"dest_ip":"192.168.1.3","dest_port":445,"proto":"TCP","pkt_src":"wire/pcap","tx_id":3,"alert":{"action":"allowed","gid":1,"signature_id":1,"rev":1,"signature":"Ascii named_pipe","category":"","severity":3},"smb":{"id":4,"dialect":"NT LM 0.12","command":"SMB1_COMMAND_TREE_CONNECT_ANDX","status":"STATUS_SUCCESS","status_code":"0x0","session_id":4096,"tree_id":2049,"tree_id":2049,"named_pipe":"\\127.0.0.1\\IPC$","service":{"request":"?????","response":"IPC"}},"app_proto":"smb","direction":"to_server","flow":{"pkts_toserver":8,"pkts_toclient":6,"bytes_toserver":1517,"bytes_toclient":1261,"start":"2020-03-10T18:22:46.069271+0000","src_ip":"192.168.1.100","dest_ip":"192.168.1.3","src_port":55768,"dest_port":445}}

When I look into the pcap, the 2049 id is not from this packet, this packet has 65535 as value in wireshark. ANd based on the command and the src/dst I would say this is the packet 11 from the pcap which is the request (check the Tree ID in wireshark).
But the packet 12 is the response which has tree id 2049. Is this expected or another bug?

Actions #5

Updated by Jason Ish almost 2 years ago

Andreas Herz wrote in #note-4:

In addition to that I would also check if we read the correct tree_id.

In `smb-named-pipe-ascii-frames` we have the following event:
[...]

When I look into the pcap, the 2049 id is not from this packet, this packet has 65535 as value in wireshark. ANd based on the command and the src/dst I would say this is the packet 11 from the pcap which is the request (check the Tree ID in wireshark).
But the packet 12 is the response which has tree id 2049. Is this expected or another bug?

SMB, I believe, correlates responses to requests before logging so you are seeing an amalgamation of the request and response being logged, and it appears to be choosing the tree_id from the response. Unfortunately, I'm not familiar enough with SMB to know what makes the most sense.

Actions #6

Updated by Jason Ish almost 2 years ago

Here are all the tests resulting in a duplicate tree_id field. In all cases that value is the same:

FAIL: ./tests/dcerpc/zerologon/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/output-eve-smb-01/output/eve.json: key=tree_id, current value=2052, new value=2052
FAIL: ./tests/smb-dce_iface/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb-dce_opnum/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb-eicar-andx/output/eve.json: key=tree_id, current value=2051, new value=2051
FAIL: ./tests/smb-eicar-file-frames/output/eve.json: key=tree_id, current value=2048, new value=2048
FAIL: ./tests/smb-eicar-file-nbss-more-ffsmb/output/eve.json: key=tree_id, current value=2052, new value=2052
FAIL: ./tests/smb-eicar-file-segmentation-postheader/output/eve.json: key=tree_id, current value=2050, new value=2050
FAIL: ./tests/smb-eicar-file-segmentation-random/output/eve.json: key=tree_id, current value=2052, new value=2052
FAIL: ./tests/smb-eicar-file/output/eve.json: key=tree_id, current value=2048, new value=2048
FAIL: ./tests/smb-eicar-overlap/output/eve.json: key=tree_id, current value=2053, new value=2053
FAIL: ./tests/smb-eicar-padding/output/eve.json: key=tree_id, current value=4102, new value=4102
FAIL: ./tests/smb-named-pipe-ascii-frames/output/eve.json: key=tree_id, current value=2049, new value=2049
FAIL: ./tests/smb-named-pipe-ascii/output/eve.json: key=tree_id, current value=2049, new value=2049
FAIL: ./tests/smb-named-pipe-unicode/output/eve.json: key=tree_id, current value=2052, new value=2052
FAIL: ./tests/smb2-01/output/eve.json: key=tree_id, current value=201977730, new value=201977730
FAIL: ./tests/smb2-02/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb2-03-rule/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb2-05/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb2-06/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb2-07-frames/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb2-07/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb2-delete/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb3-01/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb3-02-midstream/output/eve.json: key=tree_id, current value=5, new value=5
FAIL: ./tests/smb3-03-midstream/output/eve.json: key=tree_id, current value=5, new value=5
FAIL: ./tests/smb2-named-pipe-unicode/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/bug-5162/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/dcerpc-smb-fail/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/dcerpc-smb-test-01/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/filesize-keyword/output/eve.json: key=tree_id, current value=2048, new value=2048
FAIL: ./tests/streamsize-keyword/output/eve.json: key=tree_id, current value=2048, new value=2048
FAIL: ./tests/smb2-08-rule/output/eve.json: key=tree_id, current value=1, new value=1
FAIL: ./tests/smb2-async-read/output/eve.json: key=tree_id, current value=4162756537, new value=4162756537

Actions #7

Updated by Victor Julien almost 2 years ago

  • Subject changed from SMB events sometimes have duplicate `tree_id` output. to smb: tx logs sometimes have duplicate `tree_id` output
  • Label Needs backport to 6.0 added
Actions #8

Updated by Victor Julien almost 2 years ago

  • Status changed from New to In Review
  • Assignee changed from OISF Dev to Jason Ish
  • Target version changed from TBD to 7.0.0-rc1
Actions #9

Updated by Victor Julien almost 2 years ago

  • Status changed from In Review to Closed
Actions #10

Updated by Victor Julien almost 2 years ago

  • Status changed from Closed to Resolved
Actions #11

Updated by OISF Ticketbot almost 2 years ago

  • Subtask #5933 added
Actions #12

Updated by OISF Ticketbot almost 2 years ago

  • Label deleted (Needs backport to 6.0)
Actions #13

Updated by Victor Julien almost 2 years ago

  • Subtask deleted (#5933)
Actions #14

Updated by Victor Julien almost 2 years ago

  • Related to Bug #5933: smb: tx logs sometimes have duplicate `tree_id` output (6.0.x backport) added
Actions #15

Updated by Victor Julien almost 2 years ago

  • Status changed from Resolved to Closed
Actions

Also available in: Atom PDF