Flows detected on thrift port but no thrift protocol events generated

Elastic Stack Beats
1

I have configure packetbeat to process thrift-RPC on port 1463 and even though the network flow monitoring shows traffic on that port. no thrift-RPC events are generated.

packetbeat.protocols.thrift:
  ports: [1463]
  transport_type: socket
  protocol_type: binary
  enabled: true

output.console:
  enabled: true
  pretty: true

Flow event in output:

{
  "@timestamp": "2017-09-22T07:45:50.000Z",
  "beat": {
    "hostname": "XXX",
    "name": "XXX",
    "version": "5.6.1"
  },
  "connection_id": "AQAAAAAAAAA=",
  "dest": {
    "ip": "10.xxx.xxx..30",
    "port": 1463,
    "stats": {
      "net_bytes_total": 304,
      "net_packets_total": 4
    }
  },
  "final": false,
  "flow_id": "EAz/////AP//////CAwAAAEKcBIeCnATTLcFd5sBAAAAAAAAAA",
  "last_time": "2017-09-22T07:45:47.001Z",
  "source": {
    "ip": "10..xxx.xxx.76",
    "port": 39799,
    "stats": {
      "net_bytes_total": 465,
      "net_packets_total": 6
    }
  },
  "start_time": "2017-09-22T07:45:47.000Z",
  "transport": "tcp",
  "type": "flow"
}

python script that send that message creates that connection as follows:

socket = TSocket.TSocket(host=host, port=port)
transport = TTransport.TFramedTransport(socket)
protocol = TBinaryProtocol.TBinaryProtocol(trans=transport, strictRead=False, strictWrite=False)

Debug trace:
2017-09-22T08:32:06Z DBG Packet number: 1
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG Ignore empty non-FIN packet
2017-09-22T08:32:06Z DBG Packet number: 2
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG Ignore empty non-FIN packet
2017-09-22T08:32:06Z DBG Packet number: 3
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG Ignore empty non-FIN packet
2017-09-22T08:32:06Z DBG Packet number: 4
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG Connection src[10.xxx.xxx.76:49931] dst[10.xxx.xxx.30:1463] doesn't exist, creating new
2017-09-22T08:32:06Z DBG tcp flow id: 0x0
2017-09-22T08:32:06Z DBG pkt.start_seq=4182887784 pkt.last_seq=4182887833 stream.last_seq=0 (len=49)
2017-09-22T08:32:06Z DBG messageParser called parseState=0 offset=0
2017-09-22T08:32:06Z DBG method = Log

                                  test
                                      test

2017-09-22T08:32:06Z DBG offset = 49
2017-09-22T08:32:06Z DBG readMessageBegin returned: true false
2017-09-22T08:32:06Z DBG messageParser returned true false
2017-09-22T08:32:06Z DBG Out
2017-09-22T08:32:06Z DBG Packet number: 5
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG Ignore empty non-FIN packet
2017-09-22T08:32:06Z DBG Packet number: 6
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG tcp flow id: 0x0
2017-09-22T08:32:06Z DBG pkt.start_seq=3473232296 pkt.last_seq=3473232320 stream.last_seq=0 (len=24)
2017-09-22T08:32:06Z DBG messageParser called parseState=0 offset=0
2017-09-22T08:32:06Z DBG method = Log
2017-09-22T08:32:06Z DBG offset = 24
2017-09-22T08:32:06Z DBG readMessageBegin returned: true false
2017-09-22T08:32:06Z DBG messageParser returned true false
2017-09-22T08:32:06Z DBG Out
2017-09-22T08:32:06Z DBG Packet number: 7
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG Ignore empty non-FIN packet
2017-09-22T08:32:06Z DBG Packet number: 8
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG tcp flow id: 0x0
2017-09-22T08:32:06Z DBG pkt.start_seq=4182887833 pkt.last_seq=4182887833 stream.last_seq=4182887833 (len=0)
2017-09-22T08:32:06Z DBG Packet number: 9
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG tcp flow id: 0x0
2017-09-22T08:32:06Z DBG pkt.start_seq=3473232320 pkt.last_seq=3473232320 stream.last_seq=3473232320 (len=0)
2017-09-22T08:32:06Z DBG Packet number: 10
2017-09-22T08:32:06Z DBG decode packet data
2017-09-22T08:32:06Z DBG IPv4 packet
2017-09-22T08:32:06Z DBG TCP packet
2017-09-22T08:32:06Z DBG Ignore empty non-FIN packet
2017-09-22T08:32:07Z DBG Interrupted

2

Was using the wrong transport. Should have paid more attention. framed worked.

3

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.