Add a statcounter that prints statistics about the connection #117

Res260 · 2019-06-12T03:00:09Z

Logs various data about the connection when the client disconnects. Looks like this:

each field is separated so it can be used as filters and to build visualizations in ES/Kibana.

What I implemented for now:

    CONNECTION_TIME = "connectionTime"
    # Duration (in secs) for the TCP connection

    CLIENT_SERVER_RATIO = "clientServerRatio"
    # Ratio of the # of messages coming from the client vs from the server. High value (>1) means high client interaction.

    TOTAL_INPUT = "totalInput"
    # # of messages coming from the client to the server.

    TOTAL_OUTPUT = "totalOutput"
    # # of messages coming from the server to the client.

    IO_INPUT = "input"
    # Packet coming from the client to the server for the io channel

    IO_INPUT_FASTPATH = "fastPathInput"
    # Packet coming from the client to the server for the io channel as a fastpath packet

    IO_INPUT_SLOWPATH = "slowPathInput"
    # Packet coming from the client to the server for the io channel as a slowpath packet

    IO_OUTPUT = "output"
    # Packet coming from the server to the client for the io channel

    IO_OUTPUT_FASTPATH = "fastPathOutput"
    # Packet coming from the server to the client for the io channel as a fastpath packet

    IO_OUTPUT_SLOWPATH = "slowPathOutput"
    # Packet coming from the server to the client for the io channel as a slowpath packet

    MCS = "mcs"
    # Packet Coming from either end for any channel

    MCS_OUTPUT = "mcsOutput"
    # Packet Coming from the server to the client for any channel

    MCS_OUTPUT_ = "mcsOutput_"
    # Packet Coming from the server to the client for a given channel (must append channel # after it)

    MCS_INPUT = "mcsInput"
    # Packet Coming from the client to the server for any channel

    MCS_INPUT_ = "mcsInput_"
    # Packet Coming from the client to the server for a given channel (must append channel # after it)

    VIRTUAL_CHANNEL = "virtualChannel"
    # Packet Coming from either end for any virtual channel that doesnt have a specific implementation (ex clipboard)

    VIRTUAL_CHANNEL_INPUT = "virtualChannelInput"
    # Packet Coming from the client to the server for any virtual channel that doesnt have a specific implementation (ex clipboard)

    VIRTUAL_CHANNEL_OUTPUT = "virtualChannelOutput"
    # Packet Coming from the server to the client for any virtual channel that doesnt have a specific implementation (ex clipboard)

    DEVICE_REDIRECTION = "deviceRedirection"
    # Packet coming from either end for the rdpdr channel

    DEVICE_REDIRECTION_CLIENT = "deviceRedirectionClient"
    # Packet coming from the client to the server for the rdpdr channel

    DEVICE_REDIRECTION_SERVER = "deviceRedirectionServer"
    # Packet coming from the server to the client for the rdpdr channel

    DEVICE_REDIRECTION_IOREQUEST = "deviceRedirectionIORequest"
    # IORequest packets for the rdpdr channel

    DEVICE_REDIRECTION_IORESPONSE = "deviceRedirectionIOResponse"
    # IOResponse packets for the rdpdr channel

    DEVICE_REDIRECTION_IOERROR = "deviceRedirectionIOError"
    # IO error packets for the rdpdr channel

    DEVICE_REDIRECTION_FILE_CLOSE = "deviceRedirectionFileClose"
    # File Close packets for the rdpdr channel

    DEVICE_REDIRECTION_FORGED_FILE_READ = "deviceRedirectionForgedFileRead"
    # File read packets forged by pyrdp for the rdpdr channel

    DEVICE_REDIRECTION_FORGED_DIRECTORY_LISTING = "deviceRedirectionForgedDirectoryListing"
    # Directory listing packets forged by pyrdp for the rdpdr channel

    CLIPBOARD = "clipboard"
    # Number of clipboard PDUs coming from either end

    CLIPBOARD_CLIENT = "clipboardClient"
    # Number of clipboard PDUs coming from the client

    CLIPBOARD_SERVER = "clipboardServer"
    # Number of clipboard PDUs coming from the server

    CLIPBOARD_COPY = "clipboardCopies"
    # Number of times data has been copied by either end

    CLIPBOARD_PASTE = "clipboardPastes"
    # Number of times data has been pasted by either end

…disconnection - Rename mitm.py to RDPMITM.py to follow convention - Add an info log statement for virtual channel name <---> channel ID association

Pourliver · 2019-06-13T13:44:34Z

I like the idea, but I don't think it gives any useful information for a user monitoring the connection. Since it can be really good for data collection, should this be "silently" logged at a DEBUG level?

Res260 · 2019-06-13T14:36:41Z

We've had this discussion before, but debug vs info should not be honeypot vs pentest. Right now we dont have a way to differenciate both afaik. Right now, only INFO logs are written to the json file to be injested by elasticsearch.

Pourliver · 2019-06-13T14:41:38Z

My point was for both honeypot and pentest, but I didn't know that only INFO log were inside the JSON. I assumed that DEBUG were logged as well.

Res260 · 2019-06-13T14:44:12Z

The most relevant information it gives for someone monitoring the logs would be the connection time and the input / output ratio, which helps identify connections worth looking at imo

Res260 · 2019-06-13T14:45:01Z

And of course clipboard and/or rdpdr activity

Pourliver · 2019-06-19T13:50:14Z

After a few tests, I got this error message. Maybe validate the TOTAL_OUTPUT before dividing.

Unhandled Error
Traceback (most recent call last):
  File "/usr/local/lib/python3.6/dist-packages/twisted/internet/asyncioreactor.py", line 267, in run
    self._asyncioEventloop.run_forever()
  File "/usr/lib/python3.6/asyncio/base_events.py", line 427, in run_forever
    self._run_once()
  File "/usr/lib/python3.6/asyncio/base_events.py", line 1440, in _run_once
    handle._run()
  File "/usr/lib/python3.6/asyncio/events.py", line 145, in _run
    self._callback(*self._args)
--- <exception caught here> ---
  File "/usr/local/lib/python3.6/dist-packages/twisted/python/log.py", line 103, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/usr/local/lib/python3.6/dist-packages/twisted/python/log.py", line 86, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/usr/local/lib/python3.6/dist-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/local/lib/python3.6/dist-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "/usr/local/lib/python3.6/dist-packages/twisted/internet/asyncioreactor.py", line 141, in _readOrWrite
    self._disconnectSelectable(selectable, why, read)
  File "/usr/local/lib/python3.6/dist-packages/twisted/internet/posixbase.py", line 255, in _disconnectSelectable
    selectable.connectionLost(f)
  File "/usr/local/lib/python3.6/dist-packages/twisted/internet/tcp.py", line 327, in connectionLost
    protocol.connectionLost(reason)
  File "/usr/local/lib/python3.6/dist-packages/twisted/protocols/tls.py", line 403, in connectionLost
    ProtocolWrapper.connectionLost(self, reason)
  File "/usr/local/lib/python3.6/dist-packages/twisted/protocols/policies.py", line 125, in connectionLost
    self.wrappedProtocol.connectionLost(reason)
  File "/usr/local/lib/python3.6/dist-packages/pyrdp-0.2.0-py3.6-linux-x86_64.egg/pyrdp/layer/tcp.py", line 66, in connectionLost
    self.observer.onDisconnection(reason)
  File "/usr/local/lib/python3.6/dist-packages/pyrdp-0.2.0-py3.6-linux-x86_64.egg/pyrdp/core/observer.py", line 82, in __call__
    self.composite.doCall(self.item, args, kwargs)
  File "/usr/local/lib/python3.6/dist-packages/pyrdp-0.2.0-py3.6-linux-x86_64.egg/pyrdp/core/observer.py", line 56, in doCall
    getattr(observer, item)(*args, **kwargs)
  File "/usr/local/lib/python3.6/dist-packages/pyrdp-0.2.0-py3.6-linux-x86_64.egg/pyrdp/mitm/TCPMITM.py", line 80, in onClientDisconnection
    self.statCounter.stop()
  File "/usr/local/lib/python3.6/dist-packages/pyrdp-0.2.0-py3.6-linux-x86_64.egg/pyrdp/logging/StatCounter.py", line 154, in stop
    self.stats[STAT.CLIENT_SERVER_RATIO] = self.stats[STAT.TOTAL_INPUT] / self.stats[STAT.TOTAL_OUTPUT]
builtins.ZeroDivisionError: division by zero

Res260 · 2019-06-19T14:02:19Z

Right, didnt think about that but with a simple tcp scan that would trigger the error. Will update.

pyrdp/mitm/MCSMITM.py

pyrdp/logging/StatCounter.py

…bject and not a string

Res260 · 2019-06-25T00:33:24Z

The fix was simpler than I thought. Apparently something changed when @xshill refactored the logging classes and now we can put arbitrary key/values objects even if they don't appear in the "message" part of the log, which is nice.

Pourliver · 2019-06-25T12:51:25Z

So, after testing, it "works" because the log goes in the mitm.json, but here is what the console output looks like:

[2019-06-25 12:45:22,225] - INFO - Philip232610 - pyrdp.mitm.connections.tcp - Connection report

This is counter-intuitive for the user, we should either print the connection report to the user, or log it silently. This mixes both.

Res260 · 2019-06-25T12:55:33Z

Lol I overlooked that small detail, I'll take a look

…

On Tue., Jun. 25, 2019, 08:51 Maxime Carbonneau, ***@***.***> wrote: So, after testing, it "works" because the log goes in the mitm.json, but here is what the console output looks like: [2019-06-25 12:45:22,225] - INFO - Philip232610 - pyrdp.mitm.connections.tcp - Connection report This is counter-intuitive for the user, we should either print the connection report to the user, or log it silently. This mixes both. — You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub <#117?email_source=notifications&email_token=ADPMNL6CNDELTY65ZCOZ3YLP4IIE5A5CNFSM4HXE5FXKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODYQECDA#issuecomment-505430284>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ADPMNL772MUOKWZV43L3ZRTP4IIE5ANCNFSM4HXE5FXA> .

Pourliver · 2019-07-03T13:44:37Z

I tested and merged master into the branch since there was a lot of conflicts.

Res260 · 2019-07-21T21:16:42Z

Alright it should be good now @Pourliver

Pourliver · 2019-08-01T19:46:25Z

Looks good to me! Merging.

- Add a statcounter that prints statistics about the connection upon …

2e5df34

…disconnection - Rename mitm.py to RDPMITM.py to follow convention - Add an info log statement for virtual channel name <---> channel ID association

Res260 requested review from Pourliver and xshill June 12, 2019 03:00

Pourliver mentioned this pull request Jun 17, 2019

Implement a len(inputEvents) / len(outputEvents) ratio in replayer or MITM to have a measure of user interaction #46

Closed

Pourliver mentioned this pull request Jun 19, 2019

The IP of the connection isn't logged if exited before receiving ClientInfoPDU #122

Closed

Pourliver reviewed Jun 19, 2019

View reviewed changes

pyrdp/mitm/MCSMITM.py Show resolved Hide resolved

Res260 mentioned this pull request Jun 20, 2019

Added client's IP and clientData to allow client identification #123

Merged

Fix division by 0 error

3a7621f

Res260 requested a review from Pourliver June 20, 2019 22:34

Pourliver reviewed Jun 21, 2019

View reviewed changes

pyrdp/logging/StatCounter.py Outdated Show resolved Hide resolved

Fix problem where the "message" in the connection report log was an o…

ffd80a2

…bject and not a string

Merged master into statcounter

20c672b

Log all fields in the printed log statement

37b4bba

Res260 force-pushed the statcounter branch from afdfd9d to 37b4bba Compare July 21, 2019 21:16

Added comma to stat logs

dae568c

Pourliver merged commit 06c171c into master Aug 1, 2019

obilodeau deleted the statcounter branch November 27, 2019 21:53

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add a statcounter that prints statistics about the connection #117

Add a statcounter that prints statistics about the connection #117

Res260 commented Jun 12, 2019

Pourliver commented Jun 13, 2019

Res260 commented Jun 13, 2019

Pourliver commented Jun 13, 2019

Res260 commented Jun 13, 2019

Res260 commented Jun 13, 2019

Pourliver commented Jun 19, 2019 •

edited

Loading

Res260 commented Jun 19, 2019

Res260 commented Jun 25, 2019 •

edited

Loading

Pourliver commented Jun 25, 2019

Res260 commented Jun 25, 2019 via email

Pourliver commented Jul 3, 2019

Res260 commented Jul 21, 2019

Pourliver commented Aug 1, 2019

Add a statcounter that prints statistics about the connection #117

Add a statcounter that prints statistics about the connection #117

Conversation

Res260 commented Jun 12, 2019

Pourliver commented Jun 13, 2019

Res260 commented Jun 13, 2019

Pourliver commented Jun 13, 2019

Res260 commented Jun 13, 2019

Res260 commented Jun 13, 2019

Pourliver commented Jun 19, 2019 • edited Loading

Res260 commented Jun 19, 2019

Res260 commented Jun 25, 2019 • edited Loading

Pourliver commented Jun 25, 2019

Res260 commented Jun 25, 2019 via email

Pourliver commented Jul 3, 2019

Res260 commented Jul 21, 2019

Pourliver commented Aug 1, 2019

Pourliver commented Jun 19, 2019 •

edited

Loading

Res260 commented Jun 25, 2019 •

edited

Loading