SMB Logs (plus DCE-RPC, Kerberos, NTLM)

Server Message Block (SMB) is a protocol most commonly associated with Microsoft Windows enterprise administration. While there are implementations for other operating systems, such as Linux, Mac OS, FreeBSD, and the like, many security and network analysts seek information on SMB due to its use in Windows environments.

Introduction

For the most part, the log analysis sections of this document address a single Zeek log, such as conn.log or dns.log. When Zeek encounters SMB protocol usage, it usually creates multiple logs of varying types. In addition to the ubiquitous conn.log, Zeek may generate dce_rpc.log, kerberos.log, ntlm.log, smb_cmd.log, smb_files.log, smb_mapping.log, pe.log, and even notice.log entries.

This section will build upon a paper by Nate Marx published December 20, 2017 titled “An Introduction to SMB for Network Security Analysts.” The paper analyzes a set of packet captures that contain activity in a simulated compromised Windows environment.

The paper is available here:

https://401trg.github.io/pages/an-introduction-to-smb-for-network-security-analysts.html

The packet captures are available here:

https://github.com/401trg/detections/tree/master/pcaps

Thorough documentation of several versions of SMB are available online thanks to Microsoft.

SMB version 1 is posted here:

https://docs.microsoft.com/en-us/openspecs/windows_protocols/ms-smb/f210069c-7086-4dc2-885e-861d837df688

SMB versions 2 and 3 are posted here:

https://docs.microsoft.com/en-us/openspecs/windows_protocols/ms-smb2/5606ad47-5ee0-437a-817e-70c366052962

For information on the individual field values in these SMB-affiliated logs, please refer to DCE_RPC::Info, KRB::Info, NTLM::Info, SMB::CmdInfo, SMB::FileInfo, and SMB::TreeInfo.

When presenting information in this section, my general convention is to bold commands and items of interest in the resulting output.

Leveraging BZAR

Before looking at individual logs associated with SMB, it’s helpful to first consider adding the BZAR package to your repertoire.

BZAR stands for Bro/Zeek ATT&CK-based Analytics and Reporting. Mark Fernandez and others from MITRE and the Zeek community wrote BZAR to generate notice.log entries when certain patterns of activity appear in some SMB logs.

You can learn more about BZAR at https://github.com/mitre-attack/bzar and install it via the zkg package manager by saying

zkg install bzar

I suggest using BZAR when one first begins looking at SMB logs. Without BZAR, it could be difficult to know what might be worth investigating and what might be normal. However, even with BZAR, it is no easy feat to differentiate among normal, suspicious, and malicious SMB activity. Still, leveraging the BZAR policy script for Zeek will give analysts a place to begin their investigations.

Running the `net user` Command

Let’s start our investigation of SMB logs with the case labelled “RPC” in Nate Marx’s paper. The relevant packet capture file is titled 20171220_smb_net_user.pcap.

If we process the packet capture with Zeek and BZAR, the following files appear:

conn.log
dce_rpc.log
kerberos.log
notice.log
packet_filter.log
smb_mapping.log

Let’s look at the conn.log first to get a general overview of the traffic.

{
  "ts": 1507562478.10937,
  "uid": "CzgIrZ31Lh5vCHioWi",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49282,
  "id.resp_h": "192.168.10.10",
  "id.resp_p": 445,
  "proto": "tcp",
  "service": "gssapi,smb,dce_rpc,krb",
  "duration": 0.22932004928588867,
  "orig_bytes": 16271,
  "resp_bytes": 13720,
  "conn_state": "S1",
  "missed_bytes": 0,
  "history": "ShADda",
  "orig_pkts": 78,
  "orig_ip_bytes": 19403,
  "resp_pkts": 77,
  "resp_ip_bytes": 16812
}

We see that 192.168.10.31 initiated a connection to 192.168.10.10. The destination port is 445 TCP, which is associated with SMB activity. Note that Zeek observed the services on this connection as gssapi,smb,dce_rpc,krb, which represents Generic Security Service Application Programming Interface, Server Message Block, Distributed Computing Environment Remote Procedure Call, and Kerberos.

The GSS-API reference likely relates to authentication, as noted in the Windows protocol guide for SMB versions 2 and 3. It does not produce any logs named gssapi. SMB is expected as we are looking for it in this case, and will create smb-named logs. DCE-RPC is a protocol associated with Windows networking and command execution between machines, and will likely create a dce_rpc.log entry. Kerberos is an authentication protocol that will likely create a kerberos.log entry.

`notice.log`

Let’s see what the notice.log has to say about this activity.

{
  "ts": 1507562478.117387,
  "note": "ATTACK::Discovery",
  "msg": "Detected activity from host 192.168.10.31, total attempts 5 within timeframe 5.0 mins",
  "actions": [
    "Notice::ACTION_LOG"
  ],
  "suppress_for": 3600
}
{
  "ts": 1507562478.124176,
  "note": "ATTACK::Discovery",
  "msg": "Detected activity from host 192.168.10.31, total attempts 10 within timeframe 5.0 mins",
  "actions": [
    "Notice::ACTION_LOG"
  ],
  "suppress_for": 3600
}
{
  "ts": 1507562478.138992,
  "note": "ATTACK::Discovery",
  "msg": "Detected activity from host 192.168.10.31, total attempts 15 within timeframe 5.0 mins",
  "actions": [
    "Notice::ACTION_LOG"
  ],
  "suppress_for": 3600
}

These three entries all indicate the same sort of activity: 192.168.10.31 is doing some sort of “discovery” action. We do not know the nature of the reconnaissance nor do we know the target. However, when combined with the conn.log we saw previously, we can assume that 192.168.10.10 is the target.

`dce_rpc.log`

The notice.log alerted us to suspicious or malicious activity from 192.168.10.31. Perhaps the dce_rpc.log can help us understand what is happening?

Let’s look at the first entry in dce_rpc.log.

{
  "ts": 1507562478.112879,
  "uid": "CzgIrZ31Lh5vCHioWi",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49282,
  "id.resp_h": "192.168.10.10",
  "id.resp_p": 445,
  "rtt": 0.0003020763397216797,
  "named_pipe": "\\pipe\\lsass",
  "endpoint": "samr",
  "operation": "SamrConnect5"
}

This entry shows that 192.168.10.31 connected to 192.168.10.10 via a named pipe titled lsass. Microsoft’s documentation says “a pipe is a section of shared memory that processes use for communication. The process that creates a pipe is the pipe server. A process that connects to a pipe is a pipe client… Named pipes can be used to provide communication between processes on the same computer or between processes on different computers across a network.”

Ref: https://docs.microsoft.com/en-us/windows/win32/ipc/pipes

The lsass named pipe refers to the Local Security Authority Subsystem Service (LSASS). The endpoint, samr, refers to the Security Accounts Manager. Microsoft’s documentation says “the SamrConnect5 method obtains a handle to a server object.”

Ref: https://docs.microsoft.com/en-us/openspecs/windows_protocols/ms-samr/c842a897-0a42-4ca5-a607-2afd05271dae

Even if you do not fully understand all of these details (and who does!), it appears that 192.168.10.31 is trying to remotely access 192.168.10.10 in a way that requires security authentication on the client, via DCE-RPC over SMB.

All of the entries in the dce_rpc.log have the same source and destination addresses and ports. We can summarize them by extracting only the relevant fields using jq:

If we look at every one of the 46 entries in the dce_rpc.log, we will see repeats of some commands. These do not add to our general understanding of what is happening. To show a reduced set of commands, I invoke jq and pipe the output through uniq to only show unique outputs:

$ jq -c '[."named_pipe", ."endpoint", ."operation"]' dce_rpc.log | uniq

["\\pipe\\lsass","samr","SamrConnect5"]
["\\pipe\\lsass","samr","SamrEnumerateDomainsInSamServer"]
["\\pipe\\lsass","samr","SamrLookupDomainInSamServer"]
["\\pipe\\lsass","samr","SamrOpenDomain"]
["\\pipe\\lsass","samr","SamrLookupNamesInDomain"]
["\\pipe\\lsass","samr","SamrOpenUser"]
["\\pipe\\lsass","samr","SamrQueryInformationUser"]
["\\pipe\\lsass","samr","SamrQuerySecurityObject"]
["\\pipe\\lsass","samr","SamrGetGroupsForUser"]
["\\pipe\\lsass","samr","SamrGetAliasMembership"]
["\\pipe\\lsass","samr","SamrCloseHandle"]
["\\pipe\\lsass","samr","SamrConnect5"]
["\\pipe\\lsass","samr","SamrEnumerateDomainsInSamServer"]
["\\pipe\\lsass","samr","SamrLookupDomainInSamServer"]
["\\pipe\\lsass","samr","SamrOpenDomain"]
["\\pipe\\lsass","samr","SamrQueryInformationDomain"]
["\\pipe\\lsass","samr","SamrCloseHandle"]
["\\pipe\\lsass","lsarpc","LsarOpenPolicy2"]
["\\pipe\\lsass","lsarpc","LsarQueryInformationPolicy"]
["\\pipe\\lsass","samr","SamrConnect5"]
["\\pipe\\lsass","samr","SamrOpenDomain"]
["\\pipe\\lsass","samr","SamrCloseHandle"]
["\\pipe\\lsass","lsarpc","LsarLookupNames3"]
["\\pipe\\lsass","samr","SamrGetAliasMembership"]
["\\pipe\\lsass","samr","SamrCloseHandle"]
["\\pipe\\lsass","lsarpc","LsarClose"]
["\\pipe\\lsass","samr","SamrConnect5"]
["\\pipe\\lsass","samr","SamrEnumerateDomainsInSamServer"]
["\\pipe\\lsass","samr","SamrLookupDomainInSamServer"]
["\\pipe\\lsass","samr","SamrOpenDomain"]
["\\pipe\\lsass","samr","SamrLookupNamesInDomain"]
["\\pipe\\lsass","samr","SamrOpenUser"]
["\\pipe\\lsass","samr","SamrGetGroupsForUser"]
["\\pipe\\lsass","samr","SamrLookupIdsInDomain"]
["\\pipe\\lsass","samr","SamrCloseHandle"]

The bolded entries indicate that 192.168.10.31 is performing some sort of user enumeration against 192.168.10.10. Again, we don’t necessarily know exactly what all of this means, but if there is no reason from 192.168.10.31 to be performing this action, then it’s worth investigating!

`kerberos.log` and `smb_mapping.log`

Let’s see if the kerberos.log has anything new to add to our investigation.

{
  "ts": 1507562478.110863,
  "uid": "CzgIrZ31Lh5vCHioWi",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49282,
  "id.resp_h": "192.168.10.10",
  "id.resp_p": 445
}

These are the same details we found through the conn.log, but it confirms that Zeek identified Kerberos authentication in use.

The smb_mapping.log offers one entry as well:

{
  "ts": 1507562478.111677,
  "uid": "CzgIrZ31Lh5vCHioWi",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49282,
  "id.resp_h": "192.168.10.10",
  "id.resp_p": 445,
  "path": "\\\\DC1.contoso.local\\IPC$",
  "share_type": "PIPE"
}

Here we see the first mention of the IPC$ share. As noted in Mr. Marx’s paper, Windows uses the IPC$ share as a means to enable remote procedure calls. We knew this was the case when we reviewed the dce_rpc.log. It’s possible that the DC1 in the path value for this log means that 192.168.10.10 is a domain controller. It’s likely that there is user reconnaissance occurring.

If we look at the explanation for this activity noted in Mr. Marx’s paper, he says that a simulated intruder on 192.168.10.31 executed the net user command against 192.168.10.10. The intruder took this action to enumerate the user list on the target.

In the next two cases we will see what it looks like when simulated intruders move files from one system to another.

Scheduling Mimikatz via the At Service

The following analysis is based on the 20171220_smb_at_schedule.pcap and appears near the end of the RPC section of Mr. Marx’s paper.

After processing the packet capture with Zeek and BZAR, we have the following logs:

conn.log
files.log
packet_filter.log
smb_files.log

This is a short set of logs to analyze. We will start with the conn.log.

`conn.log`

Looking at the conn.log, we see one entry:

{
  "ts": 1508525002.992213,
  "uid": "Cirxt14nybZjVhpOAk",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49266,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445,
  "proto": "tcp",
  "service": "dce_rpc,smb",
  "duration": 12.397327899932861,
  "orig_bytes": 1155,
  "resp_bytes": 1037,
  "conn_state": "OTH",
  "missed_bytes": 0,
  "history": "DdAR",
  "orig_pkts": 11,
  "orig_ip_bytes": 1595,
  "resp_pkts": 9,
  "resp_ip_bytes": 1397
}

We see 192.168.10.31 initiated a connection to 192.168.10.30, port 445 TCP. Zeek recognized this as DCE RPC and SMB traffic. Note that for some reason Zeek did not create a dce_rpc.log for this activity.

`smb_files.log`

The smb_files.log holds the next clue to this activity. It contains three entries:

{
  "ts": 1508525002.992213,
  "uid": "Cirxt14nybZjVhpOAk",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49266,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445,
  "action": "SMB::FILE_OPEN",
  "name": "atsvc",
  "size": 0
}
{
  "ts": 1508525002.992213,
  "uid": "Cirxt14nybZjVhpOAk",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49266,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445,
  "action": "SMB::FILE_WRITE",
  "name": "atsvc",
  "size": 0,
  "data_offset_req": 0,
  "data_len_req": 160
}
{
  "ts": 1508525002.992213,
  "uid": "Cirxt14nybZjVhpOAk",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49266,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445,
  "fuid": "Fw42Pp34N0CC79C5Ua",
  "action": "SMB::FILE_WRITE",
  "name": "atsvc",
  "size": 0,
  "data_offset_req": 0,
  "data_len_req": 160
}

We see SMB FILE_OPEN and FILE_WRITE messages to the atsvc. This indicates that 192.168.10.31 is accessing the Windows At service, used for scheduling processes on Windows. Note that Windows and hence Zeek treats the At service as a “file,” even though it is a service offered by Windows.

`files.log`

An odd result of Windows providing the At service as a “file” is that Zeek creates a files.log entry for it. Here is that entry:

{
  "ts": 1508525002.992817,
  "fuid": "Fw42Pp34N0CC79C5Ua",
  "uid": "Cirxt14nybZjVhpOAk",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49266,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445,
  "source": "SMB",
  "depth": 0,
  "analyzers": [],
  "filename": "atsvc",
  "duration": 0.00038909912109375,
  "is_orig": true,
  "seen_bytes": 160,
  "missing_bytes": 0,
  "overflow_bytes": 0,
  "timedout": false
}

This file does not tell us anything we did not already know. Zeek did not extract a file either, because the “file” in this instance is an abstraction used to represent the At service on the Windows target.

Reviewing the Packet Capture with tshark

If administrators are authorized to use the At service to schedule jobs, from the indicated source to the indicated destination, then it may not be possible for a security analyst to identify this as malicious activity. We might be able to learn a bit more about the activity by looking at the packet capture directly.

To create the following output, I told tshark to only display the source IP address, the protocol, and the information field for each frame. I also specified that it look at SMB version 2 traffic.

$ tshark -r 20171220_smb_at_schedule.pcap -T fields -e _ws.col.No. -e _ws.col.Source -e _ws.col.Protocol -e _ws.col.Info -Y smb2

     192.168.10.31   SMB2    Create Request File: atsvc
     192.168.10.30   SMB2    Create Response File: atsvc
     192.168.10.31   SMB2    GetInfo Request FILE_INFO/SMB2_FILE_STANDARD_INFO File: atsvc
     192.168.10.30   SMB2    GetInfo Response
     192.168.10.31   DCERPC  Bind: call_id: 2, Fragment: Single, 3 context items: ATSVC V1.0 (32bit NDR), ATSVC V1.0 (64bit NDR), ATSVC V1.0 (6cb71c2c-9812-4540-0300-000000000000)
     192.168.10.30   SMB2    Write Response
     192.168.10.31   SMB2    Read Request Len:1024 Off:0 File: atsvc
     192.168.10.30   DCERPC  Bind_ack: call_id: 2, Fragment: Single, max_xmit: 4280 max_recv: 4280, 3 results: Provider rejection, Acceptance, Negotiate ACK
     192.168.10.31   ATSVC   JobAdd request
    192.168.10.30   SMB2    Ioctl Response, Error: STATUS_PENDING
    192.168.10.30   ATSVC   JobAdd response
    192.168.10.31   SMB2    Close Request File: atsvc
    192.168.10.30   SMB2    Close Response
    192.168.10.31   SMB2    Tree Disconnect Request
    192.168.10.30   SMB2    Tree Disconnect Response
    192.168.10.31   SMB2    Session Logoff Request
    192.168.10.30   SMB2    Session Logoff Response

Right away in frame 1 we see the request to create a “file” for the atsvc.

Frame 9 might have the details of the Atsvc request. We can look at the details using tshark. The -O (capital letter O) command specifies which layer of the decode we want to see.

$ tshark -r 20171220_smb_at_schedule.pcap -V -Y frame.number==9 -O atsvc

Frame 9: 338 bytes on wire (2704 bits), 338 bytes captured (2704 bits)
Ethernet II, Src: 08:00:27:7f:b5:8b, Dst: 08:00:27:a1:27:e8
Internet Protocol Version 4, Src: 192.168.10.31, Dst: 192.168.10.30
Transmission Control Protocol, Src Port: 49266, Dst Port: 445, Seq: 636, Ack: 541, Len: 284
NetBIOS Session Service
SMB2 (Server Message Block Protocol version 2)
Distributed Computing Environment / Remote Procedure Call (DCE/RPC) Request, Fragment: Single, FragLen: 160, Call: 2, Ctx: 1
Microsoft AT-Scheduler Service, JobAdd
    Operation: JobAdd (0)
    Pointer to Servername (uint16): \\admin-pc
        Referent ID: 0x0000000000020000
        Max Count: 11
        Offset: 0
        Actual Count: 11
        Server: \\admin-pc
    Pointer to Job Info (atsvc_JobInfo)
        JobInfo
            Job Time: 47100000
            Days Of Month: 0x00000000: (No values set)
                .... .... .... .... .... .... .... ...0 = First: First is NOT SET
                .... .... .... .... .... .... .... ..0. = Second: Second is NOT SET
                .... .... .... .... .... .... .... .0.. = Third: Third is NOT SET
                .... .... .... .... .... .... .... 0... = Fourth: Fourth is NOT SET
                .... .... .... .... .... .... ...0 .... = Fifth: Fifth is NOT SET
                .... .... .... .... .... .... ..0. .... = Sixth: Sixth is NOT SET
                .... .... .... .... .... .... .0.. .... = Seventh: Seventh is NOT SET
                .... .... .... .... .... .... 0... .... = Eight: Eight is NOT SET
                .... .... .... .... .... ...0 .... .... = Ninth: Ninth is NOT SET
                .... .... .... .... .... ..0. .... .... = Tenth: Tenth is NOT SET
                .... .... .... .... .... .0.. .... .... = Eleventh: Eleventh is NOT SET
                .... .... .... .... .... 0... .... .... = Twelfth: Twelfth is NOT SET
                .... .... .... .... ...0 .... .... .... = Thitteenth: Thitteenth is NOT SET
                .... .... .... .... ..0. .... .... .... = Fourteenth: Fourteenth is NOT SET
                .... .... .... .... .0.. .... .... .... = Fifteenth: Fifteenth is NOT SET
                .... .... .... .... 0... .... .... .... = Sixteenth: Sixteenth is NOT SET
                .... .... .... ...0 .... .... .... .... = Seventeenth: Seventeenth is NOT SET
                .... .... .... ..0. .... .... .... .... = Eighteenth: Eighteenth is NOT SET
                .... .... .... .0.. .... .... .... .... = Ninteenth: Ninteenth is NOT SET
                .... .... .... 0... .... .... .... .... = Twentyth: Twentyth is NOT SET
                .... .... ...0 .... .... .... .... .... = Twentyfirst: Twentyfirst is NOT SET
                .... .... ..0. .... .... .... .... .... = Twentysecond: Twentysecond is NOT SET
                .... .... .0.. .... .... .... .... .... = Twentythird: Twentythird is NOT SET
                .... .... 0... .... .... .... .... .... = Twentyfourth: Twentyfourth is NOT SET
                .... ...0 .... .... .... .... .... .... = Twentyfifth: Twentyfifth is NOT SET
                .... ..0. .... .... .... .... .... .... = Twentysixth: Twentysixth is NOT SET
                .... .0.. .... .... .... .... .... .... = Twentyseventh: Twentyseventh is NOT SET
                .... 0... .... .... .... .... .... .... = Twentyeighth: Twentyeighth is NOT SET
                ...0 .... .... .... .... .... .... .... = Twentyninth: Twentyninth is NOT SET
                ..0. .... .... .... .... .... .... .... = Thirtieth: Thirtieth is NOT SET
                .0.. .... .... .... .... .... .... .... = Thirtyfirst: Thirtyfirst is NOT SET
            Days Of Week: 0x00: (No values set)
                .... ...0 = DAYSOFWEEK MONDAY: DAYSOFWEEK_MONDAY is NOT SET
                .... ..0. = DAYSOFWEEK TUESDAY: DAYSOFWEEK_TUESDAY is NOT SET
                .... .0.. = DAYSOFWEEK WEDNESDAY: DAYSOFWEEK_WEDNESDAY is NOT SET
                .... 0... = DAYSOFWEEK THURSDAY: DAYSOFWEEK_THURSDAY is NOT SET
                ...0 .... = DAYSOFWEEK FRIDAY: DAYSOFWEEK_FRIDAY is NOT SET
                ..0. .... = DAYSOFWEEK SATURDAY: DAYSOFWEEK_SATURDAY is NOT SET
                .0.. .... = DAYSOFWEEK SUNDAY: DAYSOFWEEK_SUNDAY is NOT SET
            Flags: 0x00: (No values set)
                .... ...0 = JOB RUN PERIODICALLY: JOB_RUN_PERIODICALLY is NOT SET
                .... ..0. = JOB EXEC ERROR: JOB_EXEC_ERROR is NOT SET
                .... .0.. = JOB RUNS TODAY: JOB_RUNS_TODAY is NOT SET
                .... 0... = JOB ADD CURRENT DATE: JOB_ADD_CURRENT_DATE is NOT SET
                ...0 .... = JOB NONINTERACTIVE: JOB_NONINTERACTIVE is NOT SET
            Pointer to Command (uint16): c:\mimikatz.exe
                Referent ID: 0x0000000000020000
                Max Count: 16
                Offset: 0
                Actual Count: 16
                Command: c:\mimikatz.exe

Once you get past the spelling errors in the “Days of Month” section, we see in the “Pointer to Command” section a reference to c:mimikatz.exe. This detail was not available in the Zeek logs, but this additional information helps us recognize this activity as being likely malicious.

We can look to see if the command succeeded by reviewing the details of frame 11.

$ tshark -r 20171220_smb_at_schedule.pcap -V -Y frame.number==11 -O atsvc

Frame 11: 202 bytes on wire (1616 bits), 202 bytes captured (1616 bits)
Ethernet II, Src: 08:00:27:a1:27:e8, Dst: 08:00:27:7f:b5:8b
Internet Protocol Version 4, Src: 192.168.10.30, Dst: 192.168.10.31
Transmission Control Protocol, Src Port: 445, Dst Port: 49266, Seq: 618, Ack: 920, Len: 148
NetBIOS Session Service
SMB2 (Server Message Block Protocol version 2)
Distributed Computing Environment / Remote Procedure Call (DCE/RPC) Response, Fragment: Single, FragLen: 32, Call: 2, Ctx: 1, [Req: #9]
Microsoft AT-Scheduler Service, JobAdd
    Operation: JobAdd (0)
    [Request in frame: 9]
    Pointer to Job Id (uint32)
        Job Id: 2
    NT Error: STATUS_SUCCESS (0x00000000)

The NT Error message shows STATUS_SUCCESS, which indicates that the job was scheduled via the At service.

In the next section we will introduce another capability associated with Windows lateral movement.

Using PsExec to Retrieve a File from a Target

Microsoft describes PsExec in the following terms:

“PsExec is a light-weight telnet-replacement that lets you execute processes on other systems, complete with full interactivity for console applications, without having to manually install client software. PsExec’s most powerful uses include launching interactive command-prompts on remote systems and remote-enabling tools like IpConfig that otherwise do not have the ability to show information about remote systems.”

Ref: https://docs.microsoft.com/en-us/sysinternals/downloads/psexec

Intruders are fond of PsExec for the very capabilities that Microsoft describes.

The following analysis is based on the 20171220_smb_psexec_mimikatz_ticket_dump.pcap file described in the PsExec section of Nate Marx’s paper.

Zeek creates the following output for this packet capture, along with an extract_files/ directory. I use the wc command to show how many lines appear in each file.

$ wc -l *.log

conn.log
dce_rpc.log
dns.log
files.log
kerberos.log
notice.log
packet_filter.log
pe.log
smb_files.log
smb_mapping.log

We’ll start with the conn.log but move to the notice.log quickly thereafter.

`conn.log`

Because we saw that there were 9 entries in the conn.log, I’m going to summarize them using the following command:

$ jq -c '[."uid", ."id.orig_h", ."id.resp_h", ."id.resp_p", ."proto", ."service"]' conn.log

["CT7qITytKtae83Tyi","192.168.10.31","192.168.10.10",88,"tcp","krb_tcp"]
["CBFaLB1HJivXnb9Jw2","192.168.10.31","192.168.10.30",135,"tcp","dce_rpc"]
["CqgZIa4KYnX4cNHJo8","192.168.10.31","192.168.10.30",49155,"tcp","dce_rpc"]
["C95D4lsjb4GjGbBq2","192.168.10.31","192.168.10.255",137,"udp","dns"]
["CEcy2LEJUZQrLwO4b","192.168.10.31","192.168.10.10",53,"udp","dns"]
["CPlgJVWL9yrKdUsX8","192.168.10.31","192.168.10.10",53,"udp","dns"]
["C6zoLD2QgM71nvWdX5","192.168.10.30","192.168.10.255",137,"udp","dns"]
["C6HQVsDf8VCu0XTJe","192.168.10.31","192.168.10.30",445,"tcp","smb,krb,gssapi"]
["Cishox1cH3JLghxiV8","192.168.10.31","192.168.10.10",3,"icmp",null]

The 4 TCP connections likely are the sessions we want to investigate in this case. However, because we have a notice.log for this activity, it’s smartest to look at those entries next.

`notice.log`

The notice.log for this activity has 8 entries. I tried to distill them to the bare minimum required to convey what is happening, according to Zeek and BZAR.

$ jq -c '[."uid", ."note", ."msg", ."sub", ."src", ."dst"]' notice.log | uniq

["C6HQVsDf8VCu0XTJe","ATTACK::Lateral_Movement","Detected SMB::FILE_WRITE to admin file share '\\\\admin-pc\\ADMIN$PSEXESVC.exe'","T1021.002 Remote Services: SMB/Windows Admin Shares + T1570 Lateral Tool Transfer","192.168.10.31","192.168.10.30"]

["C6HQVsDf8VCu0XTJe","ATTACK::Lateral_Movement_Extracted_File","Saved a copy of the file written to SMB admin file share","C6HQVsDf8VCu0XTJe_FtIFnm3ZqI1s96P74l__admin-pc_ADMIN$PSEXESVC.exe","192.168.10.31","192.168.10.30"]

["CqgZIa4KYnX4cNHJo8","ATTACK::Execution","svcctl::CreateServiceWOW64W","T1569.002 System Services: Service Execution","192.168.10.31","192.168.10.30"]

[null,"ATTACK::Lateral_Movement_and_Execution","Detected activity against host 192.168.10.30, total score 1004 within timeframe 10.0 mins",null,null,null]

["CqgZIa4KYnX4cNHJo8","ATTACK::Execution","svcctl::StartServiceW","T1569.002 System Services: Service Execution","192.168.10.31","192.168.10.30"]

The highlighted fields indicate suspicious or malicious activity. We see evidence of lateral tool transfer to 192.168.10.30 via SMB of a file named psexecsvc.exe, then service execution.

`dce_rpc.log`

Let’s see if the dce_rpc.log adds any useful details. We saw earlier that this log has 20 entries. The first two shows us the pattern that occupies all 20 entries.

{
  "ts": 1507565599.588936,
  "uid": "CBFaLB1HJivXnb9Jw2",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49240,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 135,
  "rtt": 0.0002448558807373047,
  "named_pipe": "135",
  "endpoint": "epmapper",
  "operation": "ept_map"
}

{
  "ts": 1507565599.601632,
  "uid": "CqgZIa4KYnX4cNHJo8",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49241,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 49155,
  "rtt": 0.0003237724304199219,
  "named_pipe": "49155",
  "endpoint": "svcctl",
  "operation": "OpenSCManagerW"
}

The first entry shows a call to the Windows endpoint mapper, epmapper, on port 135 TCP on 192.168.10.30. The response from this service directs the client 192.168.10.31 to port 49155 TCP on 192.168.10.30. The second and subsequent dce_rpc.log entries involve port 49155 TCP on the target, which is offering svcctrl.

We see the target IP address is 192.168.10.30, confirming the activity in the notice.log. As we did with a previous dce_rpc.log, we can simplify this one into the following entries:

$ jq -c '[."named_pipe", ."endpoint", ."operation"]' dce_rpc.log | uniq

["135","epmapper","ept_map"]
["49155","svcctl","OpenSCManagerW"]
["49155","svcctl","CreateServiceWOW64W"]
["49155","svcctl","CloseServiceHandle"]
["49155","svcctl","OpenServiceW"]
["49155","svcctl","StartServiceW"]
["49155","svcctl","QueryServiceStatus"]
["49155","svcctl","CloseServiceHandle"]
["49155","svcctl","OpenSCManagerW"]
["49155","svcctl","OpenServiceW"]
["49155","svcctl","ControlService"]
["49155","svcctl","QueryServiceStatus"]
["49155","svcctl","CloseServiceHandle"]
["49155","svcctl","OpenServiceW"]
["49155","svcctl","DeleteService"]
["49155","svcctl","CloseServiceHandle"]

We see some sort of successful interaction with the svcctrl service on the target.

Incidentally, we can’t see much more using a protocol analyzer like tshark, either:

$ tshark -r 20171220_smb_psexec_mimikatz_ticket_dump.pcap -V -Y frame.number==76 -O svcctl

Frame 76: 258 bytes on wire (2064 bits), 258 bytes captured (2064 bits)
Ethernet II, Src: 08:00:27:7f:b5:8b, Dst: 08:00:27:a1:27:e8
Internet Protocol Version 4, Src: 192.168.10.31, Dst: 192.168.10.30
Transmission Control Protocol, Src Port: 49241, Dst Port: 49155, Seq: 1945, Ack: 366, Len: 204
Distributed Computing Environment / Remote Procedure Call (DCE/RPC) Request, Fragment: Single, FragLen: 204, Call: 2, Ctx: 0
Microsoft Service Control, OpenSCManagerW
    Operation: OpenSCManagerW (15)
    Encrypted stub data: 02353eb074e7e350b9632e05b550f725c99d41d419165110...

As Mr. Marx notes in his paper, the content of these exchanges are encrypted within the Microsoft Service Control layer.

`kerberos.log`

The kerberos.log contains two entries:

{
  "ts": 1507565599.590346,
  "uid": "CT7qITytKtae83Tyi",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49242,
  "id.resp_h": "192.168.10.10",
  "id.resp_p": 88,
  "request_type": "TGS",
  "client": "RonHD/CONTOSO.LOCAL",
  "service": "HOST/admin-pc",
  "success": true,
  "till": 2136422885,
  "cipher": "aes256-cts-hmac-sha1-96",
  "forwardable": true,
  "renewable": true
}
{
  "ts": 1507565599.575721,
  "uid": "C6HQVsDf8VCu0XTJe",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49239,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445
}

The first entry includes the acronym TGS, which means Ticket Granting service. The system 192.168.10.10 appears to be a domain controller, as we saw in an earlier case. We gather some information on the intruder’s system, namely that it is RonHD in the CONTOSO.LOCAL domain.

The second entry shows that the aggressor 192.168.10.31 used Kerberos to authenticate to the target 192.168.10.30.

`smb_mapping.log`

The smb_mapping.log contains two entries:

{
  "ts": 1507565599.576613,
  "uid": "C6HQVsDf8VCu0XTJe",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49239,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445,
  "path": "\\\\admin-pc\\ADMIN$",
  "share_type": "DISK"
}
{
  "ts": 1507565599.729707,
  "uid": "C6HQVsDf8VCu0XTJe",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49239,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445,
  "path": "\\\\admin-pc\\IPC$",
  "share_type": "PIPE"
}

As we learned earlier, connections to the ADMIN$ and IPC$ shares on a target system are suspicious or malicious if they are not already authorized.

`smb_files.log`

There are many entries in the smb_files.log. The first looks like this:

{
  "ts": 1507565599.576942,
  "uid": "C6HQVsDf8VCu0XTJe",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49239,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445,
  "action": "SMB::FILE_OPEN",
  "path": "\\\\admin-pc\\ADMIN$",
  "name": "PSEXESVC.exe",
  "size": 0,
  "times.modified": 1507565599.607777,
  "times.accessed": 1507565599.607777,
  "times.created": 1507565599.607777,
  "times.changed": 1507565599.607777
}

As we noted earlier, use of psexecsvc.exe is likely malicious as intruders use it to run PsExec on remote systems.

We can summarize all of the entries in smb_files.log with the following syntax:

$ jq -c '[."action", ."path", ."name"]' smb_files.log

["SMB::FILE_OPEN","\\\\admin-pc\\ADMIN$","PSEXESVC.exe"]
["SMB::FILE_WRITE","\\\\admin-pc\\ADMIN$","PSEXESVC.exe"]
["SMB::FILE_WRITE","\\\\admin-pc\\ADMIN$","PSEXESVC.exe"]
["SMB::FILE_OPEN","\\\\admin-pc\\ADMIN$","PSEXESVC.exe"]
["SMB::FILE_DELETE","\\\\admin-pc\\ADMIN$","PSEXESVC.exe"]

This does not give us any more context but it shows the sorts of data in the smb_files.log.

`extract_files/`, `files.log`, and `pe.log`, and VirusTotal

As we did in a previous case, we can look into the files that Zeek and BZAR captured for this activity.

The extract_files/ directory contains one executable file:

extract_files/C6HQVsDf8VCu0XTJe_FtIFnm3ZqI1s96P74l__admin-pc_ADMIN$PSEXESVC.exe: PE32 executable (console) Intel 80386, for MS Windows

Zeek’s files.log says the following about it:

{
  "ts": 1507565599.578328,
  "fuid": "FtIFnm3ZqI1s96P74l",
  "uid": "C6HQVsDf8VCu0XTJe",
  "id.orig_h": "192.168.10.31",
  "id.orig_p": 49239,
  "id.resp_h": "192.168.10.30",
  "id.resp_p": 445,
  "source": "SMB",
  "depth": 0,
  "analyzers": [
    "MD5",
    "SHA1",
    "PE",
    "EXTRACT",
    "SHA256"
  ],
  "mime_type": "application/x-dosexec",
  "filename": "PSEXESVC.exe",
  "duration": 0.0006651878356933594,
  "is_orig": true,
  "seen_bytes": 145568,
  "missing_bytes": 0,
  "overflow_bytes": 0,
  "timedout": false,
  "md5": "75b55bb34dac9d02740b9ad6b6820360",
  "sha1": "a17c21b909c56d93d978014e63fb06926eaea8e7",
  "sha256": "141b2190f51397dbd0dfde0e3904b264c91b6f81febc823ff0c33da980b69944",
  "extracted": "C6HQVsDf8VCu0XTJe_FtIFnm3ZqI1s96P74l__admin-pc_ADMIN$PSEXESVC.exe",
  "extracted_cutoff": false
}

Zeek’s pe.log says the following:

{
  "ts": 1507565599.578328,
  "id": "FtIFnm3ZqI1s96P74l",
  "machine": "I386",
  "compile_ts": 1467139314,
  "os": "Windows XP",
  "subsystem": "WINDOWS_CUI",
  "is_exe": true,
  "is_64bit": false,
  "uses_aslr": true,
  "uses_dep": true,
  "uses_code_integrity": false,
  "uses_seh": true,
  "has_import_table": true,
  "has_export_table": false,
  "has_cert_table": true,
  "has_debug_data": false,
  "section_names": [
    ".text",
    ".rdata",
    ".data",
    ".rsrc",
    ".reloc"
  ]
}

The compile time translates to human readable format as this:

$ date -d @1467139314

Tue Jun 28 18:41:54 UTC 2016

We can also check VirusTotal using the MD5 hash:

$ vt file "75b55bb34dac9d02740b9ad6b6820360"

- _id: "141b2190f51397dbd0dfde0e3904b264c91b6f81febc823ff0c33da980b69944"
  _type: "file"
  authentihash: "62287971b29db5858ceaf92e9db310862e9082608f9dd3ac7f5ed3f71c7cfc38"
  creation_date: 1467139314  # 2016-06-28 18:41:54 +0000 UTC
  first_seen_itw_date: 1463443155  # 2016-05-16 23:59:15 +0000 UTC
  first_submission_date: 1467293310  # 2016-06-30 13:28:30 +0000 UTC
  last_analysis_date: 1606108041  # 2020-11-23 05:07:21 +0000 UTC
  last_analysis_results:
    ALYac:
      category: "undetected"
      engine_name: "ALYac"
      engine_update: "20201123"
      engine_version: "1.1.1.5"
      method: "blacklist"
...truncated…

The various dates for this copy of PsExecSvc are interesting.

I am not sure how to account for a first seen in the wild date that precedes the creation date. I think it’s interesting that only a few hours before I worked with this sample, someone else was doing the same thing, but via uploading the executable!

After this analysis, all we know is that PsExecSvc is being used successfully against 192.168.10.31. Mr. Marx’s paper notes that his activity involved retrieving a file from the target. We cannot tell that from these logs. This is an example of using Zeek logs to identify suspicious or malicious activity, and then pivoting to host-centric data to determine exactly what is happening.

`ntlm.log`

One log we have not seen in any of these cases is the ntlm.log. This log captures old-style Windows NT Lan Manager (NTLM) authentication details. The packet capture smb-on-windows-10.pcapng provided by the Wireshark project produces a ntlm.log when Zeek processes it.

Ref: https://wiki.wireshark.org/SMB2

{
  "ts": 1476605364.033848,
  "uid": "CNicnvp8Qdqbqm96a",
  "id.orig_h": "192.168.199.133",
  "id.orig_p": 49672,
  "id.resp_h": "192.168.199.1",
  "id.resp_p": 139,
  "hostname": "DESKTOP-V1FA0UQ",
  "server_nb_computer_name": "SCV",
  "server_dns_computer_name": "SCV",
  "success": true
}
{
  "ts": 1476605590.442053,
  "uid": "CLVEN87g2bfZgXqP5",
  "id.orig_h": "192.168.199.132",
  "id.orig_p": 49670,
  "id.resp_h": "192.168.199.133",
  "id.resp_p": 445,
  "username": "user",
  "hostname": "DESKTOP-2AEFM7G",
  "domainname": "DESKTOP-2AEFM7G",
  "server_nb_computer_name": "DESKTOP-V1FA0UQ",
  "server_dns_computer_name": "DESKTOP-V1FA0UQ"
}
{
  "ts": 1476605590.474118,
  "uid": "C74tDzQl0ttE8v813",
  "id.orig_h": "192.168.199.132",
  "id.orig_p": 49671,
  "id.resp_h": "192.168.199.133",
  "id.resp_p": 445,
  "username": "user",
  "hostname": "DESKTOP-2AEFM7G",
  "domainname": "DESKTOP-2AEFM7G",
  "server_nb_computer_name": "DESKTOP-V1FA0UQ",
  "server_dns_computer_name": "DESKTOP-V1FA0UQ"
}
{
  "ts": 1476605590.484196,
  "uid": "CzLJgJ2nrXGMxvnXze",
  "id.orig_h": "192.168.199.132",
  "id.orig_p": 49672,
  "id.resp_h": "192.168.199.133",
  "id.resp_p": 445,
  "username": "user",
  "hostname": "DESKTOP-2AEFM7G",
  "domainname": "DESKTOP-2AEFM7G",
  "server_nb_computer_name": "DESKTOP-V1FA0UQ",
  "server_dns_computer_name": "DESKTOP-V1FA0UQ"
}
{
  "ts": 1476605590.496004,
  "uid": "Ct46uQ2dOQuqnp5YPj",
  "id.orig_h": "192.168.199.132",
  "id.orig_p": 49673,
  "id.resp_h": "192.168.199.133",
  "id.resp_p": 445,
  "username": "user",
  "hostname": "DESKTOP-2AEFM7G",
  "domainname": "DESKTOP-2AEFM7G",
  "server_nb_computer_name": "DESKTOP-V1FA0UQ",
  "server_dns_computer_name": "DESKTOP-V1FA0UQ"
}
{
  "ts": 1476605609.93236,
  "uid": "CQorcF2L5fLEA4EImh",
  "id.orig_h": "192.168.199.132",
  "id.orig_p": 49674,
  "id.resp_h": "192.168.199.133",
  "id.resp_p": 445,
  "username": "Tim Tester",
  "hostname": "DESKTOP-2AEFM7G",
  "domainname": "DESKTOP-2AEFM7G",
  "server_nb_computer_name": "DESKTOP-V1FA0UQ",
  "server_dns_computer_name": "DESKTOP-V1FA0UQ"
}
{
  "ts": 1476605761.4297,
  "uid": "CBbRT6X875vQPAgJj",
  "id.orig_h": "192.168.199.132",
  "id.orig_p": 49675,
  "id.resp_h": "192.168.199.133",
  "id.resp_p": 445,
  "username": "Willi Wireshark",
  "hostname": "DESKTOP-2AEFM7G",
  "domainname": "DESKTOP-2AEFM7G",
  "server_nb_computer_name": "DESKTOP-V1FA0UQ",
  "server_dns_computer_name": "DESKTOP-V1FA0UQ",
  "success": true
}

This pcap produces a lot of Zeek logs, so I wanted to only show these entries. Analysts would probably take two investigative steps. First, should 192.168.199.132 be trying to access these other systems? Second, should the authentication have succeeded, as denoted by the two “true” results?

Conclusion

This has been a large section, but the goal was to present a set of cases and show how Zeek and BZAR (when available) made sense of them. I recommend reading Mr. Marx’s paper for more details as well.

SMB Logs (plus DCE-RPC, Kerberos, NTLM)

Introduction

Leveraging BZAR

Running the net user Command

notice.log

dce_rpc.log

kerberos.log and smb_mapping.log

Connecting to a SMB Share and Uploading a File

conn.log

notice.log

extract_files/, files.log, and pe.log, and VirusTotal

kerberos.log, smb_mapping.log, and smb_files.log

Connecting to a SMB Share and Downloading a File

conn.log

files.log and pe.log

kerberos.log, smb_mapping.log, and smb_files.log

Scheduling Mimikatz via the At Service

conn.log

smb_files.log

files.log

Reviewing the Packet Capture with tshark

Using PsExec to Retrieve a File from a Target

conn.log

notice.log

dce_rpc.log

kerberos.log

smb_mapping.log

smb_files.log

extract_files/, files.log, and pe.log, and VirusTotal

ntlm.log

Conclusion

Running the `net user` Command

`notice.log`

`dce_rpc.log`

`kerberos.log` and `smb_mapping.log`

`conn.log`

`notice.log`

`extract_files/`, `files.log`, and `pe.log`, and VirusTotal

`kerberos.log`, `smb_mapping.log`, and `smb_files.log`

`conn.log`

`files.log` and `pe.log`

`kerberos.log`, `smb_mapping`.log, and `smb_files.log`

`conn.log`

`smb_files.log`

`files.log`

`conn.log`

`notice.log`

`dce_rpc.log`

`kerberos.log`

`smb_mapping.log`

`smb_files.log`

`extract_files/`, `files.log`, and `pe.log`, and VirusTotal

`ntlm.log`