2019-10-24 17:45:24 +00:00
|
|
|
#!/usr/bin/python3
|
|
|
|
|
# -*- coding: utf-8 -*-
|
|
|
|
|
#
|
|
|
|
|
# script to read pcap file (communcation with khanat)
|
|
|
|
|
#
|
|
|
|
|
# Copyright (C) 2019 AleaJactaEst
|
|
|
|
|
#
|
|
|
|
|
# This program is free software: you can redistribute it and/or modify
|
|
|
|
|
# it under the terms of the GNU General Public License as published by
|
|
|
|
|
# the Free Software Foundation, either version 3 of the License, or
|
|
|
|
|
# (at your option) any later version.
|
|
|
|
|
#
|
|
|
|
|
# This program is distributed in the hope that it will be useful,
|
|
|
|
|
# but WITHOUT ANY WARRANTY; without even the implied warranty of
|
|
|
|
|
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
|
|
|
|
|
# GNU General Public License for more details.
|
|
|
|
|
#
|
|
|
|
|
# You should have received a copy of the GNU General Public License
|
|
|
|
|
# along with this program. If not, see <http://www.gnu.org/licenses/>.
|
|
|
|
|
|
|
|
|
|
# Ex.:
|
|
|
|
|
# sudo tcpdump -i docker0 -w capture2.pcap
|
|
|
|
|
# ./spykhanat.py --pcap-file=../capture2.pcap --msg-xml=../khanat-opennel-code/code/ryzom/common/data_common/msg.xml
|
|
|
|
|
|
|
|
|
|
import argparse
|
|
|
|
|
import logging
|
|
|
|
|
from pcapfile import savefile
|
|
|
|
|
from pcapfile.protocols.linklayer import ethernet
|
|
|
|
|
from pcapfile.protocols.network import ip
|
|
|
|
|
from pcapfile.protocols.transport import udp
|
|
|
|
|
from pcapfile.protocols.transport import tcp
|
|
|
|
|
import binascii
|
|
|
|
|
import re
|
|
|
|
|
from tools import BitStream
|
|
|
|
|
from tools import Enum
|
|
|
|
|
from tools import CActionFactory
|
|
|
|
|
from tools import CBitSet
|
|
|
|
|
from tools import DecodeImpulse
|
|
|
|
|
from tools import World
|
|
|
|
|
from tools import CGenericMultiPartTemp
|
|
|
|
|
from tools import CImpulseDecoder
|
|
|
|
|
from tools import CStringManager
|
|
|
|
|
from tools import CAction
|
|
|
|
|
import xml.etree.ElementTree as ET
|
2019-11-03 12:42:13 +00:00
|
|
|
from datetime import datetime
|
2019-10-24 17:45:24 +00:00
|
|
|
|
|
|
|
|
LOGGER = 'SpyKhanat'
|
|
|
|
|
|
|
|
|
|
#file = open('capture2.pcap' , 'rb')
|
|
|
|
|
#pcapfile = savefile.load_savefile(file,verbose=True)
|
|
|
|
|
#pkt = pcapfile.packets[0]
|
|
|
|
|
#print(pkt.raw())
|
|
|
|
|
#print(pkt.timestamp)
|
|
|
|
|
#eth_frame = ethernet.Ethernet(pkt.raw())
|
|
|
|
|
#print(eth_frame)
|
|
|
|
|
#ip_packet = ip.IP(binascii.unhexlify(eth_frame.payload))
|
|
|
|
|
#print(ip_packet)
|
|
|
|
|
|
|
|
|
|
class SpyPcap():
|
2019-11-06 20:36:42 +00:00
|
|
|
def __init__(self, khanat_host_service, pcap_file, msg_xml, filter_host_service, show_raw_packet, show_message_decoded, outyaml=None):
|
2019-10-24 17:45:24 +00:00
|
|
|
if khanat_host_service:
|
|
|
|
|
self.khanat_host_service = re.compile(khanat_host_service)
|
|
|
|
|
else:
|
|
|
|
|
self.khanat_host_service = None
|
|
|
|
|
self.pcap_file = pcap_file
|
|
|
|
|
self.msg_xml = msg_xml
|
|
|
|
|
if filter_host_service:
|
|
|
|
|
self.filter_host_service = re.compile(filter_host_service)
|
|
|
|
|
else:
|
|
|
|
|
self.filter_host_service = None
|
|
|
|
|
self.show_raw_packet = show_raw_packet
|
|
|
|
|
self.show_message_decoded = show_message_decoded
|
|
|
|
|
self.actionFactory = CActionFactory.CActionFactory(None)
|
|
|
|
|
self.client_state = {}
|
|
|
|
|
self.decodeImpulse = DecodeImpulse.DecodeImpulse()
|
|
|
|
|
|
|
|
|
|
fp = open(msg_xml , 'rt')
|
|
|
|
|
msgRawXml = fp.read()
|
|
|
|
|
self.msgXml = ET.fromstring(msgRawXml)
|
|
|
|
|
self.decodeImpulse.loadMsg(self.msgXml)
|
2019-11-06 20:36:42 +00:00
|
|
|
self.outyaml = outyaml
|
2019-10-24 17:45:24 +00:00
|
|
|
|
|
|
|
|
def readRaw(self):
|
|
|
|
|
file = open( self.pcap_file , 'rb')
|
|
|
|
|
pcapfile = savefile.load_savefile(file,verbose=False)
|
|
|
|
|
for pkt in pcapfile.packets:
|
|
|
|
|
print("pkt:", dir(pkt))
|
|
|
|
|
print("pkt.header:", dir(pkt.header))
|
|
|
|
|
print("pkt.packet:", dir(pkt.packet))
|
|
|
|
|
logging.getLogger(LOGGER).debug("raw: %s" % pkt.raw())
|
2019-11-03 12:42:13 +00:00
|
|
|
logging.getLogger(LOGGER).debug("timestamp: %s (%s)" % (pkt.timestamp,datetime.fromtimestamp(pkt.timestamp).strftime("%Y/%m/%d %H:%M:%S")))
|
2019-10-24 17:45:24 +00:00
|
|
|
eth_frame = ethernet.Ethernet(pkt.raw())
|
|
|
|
|
logging.getLogger(LOGGER).debug("eth_frame: %s" % eth_frame)
|
|
|
|
|
if eth_frame.type == 2048:
|
|
|
|
|
ip_packet = ip.IP(binascii.unhexlify(eth_frame.payload))
|
|
|
|
|
logging.getLogger(LOGGER).debug("ip packet: %s" % ip_packet)
|
|
|
|
|
print("ip_packet:", dir(ip_packet))
|
|
|
|
|
logging.getLogger(LOGGER).debug("ip packet: %s ->%s" % (ip_packet.src.decode(), ip_packet.dst.decode()) )
|
|
|
|
|
if ip_packet.p == 17:
|
|
|
|
|
# UDP
|
|
|
|
|
logging.getLogger(LOGGER).debug("ip packet: protocol UDP (%s)" % ip_packet.p)
|
|
|
|
|
udp_packet = udp.UDP(binascii.unhexlify(ip_packet.payload))
|
|
|
|
|
print("udp_packet:", dir(udp_packet))
|
|
|
|
|
logging.getLogger(LOGGER).debug("UDP packet: %s" % udp_packet)
|
|
|
|
|
data = udp_packet.payload
|
|
|
|
|
print("data:", dir(data))
|
|
|
|
|
logging.getLogger(LOGGER).debug("data packet: %s" % data)
|
|
|
|
|
data = udp_packet.payload
|
|
|
|
|
logging.getLogger(LOGGER).info("data packet: timestamp:%s src:%s:%d dst:%s:%d data:%s" % (pkt.timestamp,
|
|
|
|
|
ip_packet.src.decode(), udp_packet.src_port,
|
|
|
|
|
ip_packet.dst.decode(), udp_packet.dst_port,
|
|
|
|
|
data.decode()))
|
|
|
|
|
|
|
|
|
|
elif ip_packet.p == 6:
|
|
|
|
|
# TCP
|
|
|
|
|
logging.getLogger(LOGGER).debug("ip packet: protocol TCP (%s)" % ip_packet.p)
|
|
|
|
|
tcp_packet = tcp.TCP(binascii.unhexlify(ip_packet.payload))
|
|
|
|
|
data = tcp_packet.payload
|
|
|
|
|
logging.getLogger(LOGGER).info("data packet: timestamp:%s src:%s:%d dst:%s:%d data:%s" % (pkt.timestamp,
|
|
|
|
|
ip_packet.src.decode(), tcp_packet.src_port,
|
|
|
|
|
ip_packet.dst.decode(), tcp_packet.dst_port,
|
|
|
|
|
data.decode()))
|
|
|
|
|
else:
|
|
|
|
|
logging.getLogger(LOGGER).debug("ip packet: protocol (%s)" % ip_packet.p)
|
|
|
|
|
|
|
|
|
|
def detect_khanat_server(self, packets):
|
|
|
|
|
hostdetected = {}
|
|
|
|
|
for pkt in packets:
|
|
|
|
|
eth_frame = ethernet.Ethernet(pkt.raw())
|
|
|
|
|
if eth_frame.type == 2048:
|
|
|
|
|
ip_packet = ip.IP(binascii.unhexlify(eth_frame.payload))
|
|
|
|
|
if ip_packet.p == 17: # UDP
|
|
|
|
|
udp_packet = udp.UDP(binascii.unhexlify(ip_packet.payload))
|
|
|
|
|
data = udp_packet.payload
|
|
|
|
|
host = "%s:%d" % (ip_packet.src.decode(), udp_packet.src_port)
|
|
|
|
|
hostdetected.setdefault(host, 0)
|
|
|
|
|
if len(data) == 20:
|
|
|
|
|
hostdetected[host] += 1
|
|
|
|
|
id = None
|
|
|
|
|
max = 0
|
|
|
|
|
for host in hostdetected:
|
|
|
|
|
if id:
|
|
|
|
|
if max < hostdetected[host]:
|
|
|
|
|
max = hostdetected[host]
|
|
|
|
|
id = host
|
|
|
|
|
else:
|
|
|
|
|
max = hostdetected[host]
|
|
|
|
|
id = host
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info(" host :%s" % id)
|
2019-10-24 17:45:24 +00:00
|
|
|
return id
|
|
|
|
|
|
|
|
|
|
def initialize_client(self, clientid):
|
|
|
|
|
self.client_state.setdefault(clientid, {'CurrentReceivedNumber': 0,
|
|
|
|
|
'CurrentSendNumber': 0,
|
|
|
|
|
'LastReceivedAck': 0,
|
2019-11-03 12:42:13 +00:00
|
|
|
'AckBitMask': 0,
|
2019-10-24 17:45:24 +00:00
|
|
|
'RegisteredAction': {},
|
|
|
|
|
'world': World.World(),
|
|
|
|
|
'GenericMultiPartTemp': CGenericMultiPartTemp.GenericMultiPartTemp(),
|
|
|
|
|
'CImpulseDecoder': None,
|
2019-11-06 13:13:23 +00:00
|
|
|
'CActionFactory': None,
|
2019-10-24 17:45:24 +00:00
|
|
|
'LastAck0': [-1],
|
|
|
|
|
'LastAck1': [-1, -1],
|
|
|
|
|
'LastAck2': [-1, -1, -1, -1]})
|
|
|
|
|
self.client_state[clientid]['CImpulseDecoder'] = CImpulseDecoder.CImpulseDecoder(self.client_state[clientid]['world'])
|
2019-11-06 13:13:23 +00:00
|
|
|
self.client_state[clientid]['CActionFactory'] = CActionFactory.CActionFactory(self.client_state[clientid]['world'])
|
2019-10-24 17:45:24 +00:00
|
|
|
|
|
|
|
|
def add_registered_action(self, clientid, action):
|
|
|
|
|
self.client_state[clientid]['RegisteredAction'].setdefault(action.Code, [])
|
|
|
|
|
self.client_state[clientid]['RegisteredAction'][action.Code].append(action)
|
|
|
|
|
|
|
|
|
|
def decode_server(self, clientid, msgin, receivedPacket, receivedAck, nextSentPacket=0):
|
|
|
|
|
actions = []
|
|
|
|
|
for level in range(0, 3):
|
|
|
|
|
if level == 0:
|
|
|
|
|
lAck = self.client_state[clientid]['LastAck0']
|
|
|
|
|
channel = 0
|
|
|
|
|
elif level == 1:
|
|
|
|
|
lAck = self.client_state[clientid]['LastAck1']
|
|
|
|
|
channel = receivedPacket & 1
|
|
|
|
|
elif level == 2:
|
|
|
|
|
lAck = self.client_state[clientid]['LastAck2']
|
|
|
|
|
channel = receivedPacket & 3
|
|
|
|
|
keep = True
|
|
|
|
|
checkOnce = False
|
|
|
|
|
num = 0
|
|
|
|
|
#logging.getLogger(LOGGER).debug("level:%d channel:%d lAck:%s" %(level, channel, ':'.join([str(x) for x in lAck])))
|
|
|
|
|
# lastAck = lAck[channel]
|
|
|
|
|
while True:
|
|
|
|
|
next = msgin.readBool('next:' + str(level) + ':' + str(channel))
|
|
|
|
|
if not next:
|
|
|
|
|
break
|
|
|
|
|
if not checkOnce:
|
|
|
|
|
checkOnce = True
|
|
|
|
|
keep = receivedAck >= lAck[channel]
|
|
|
|
|
logging.getLogger(LOGGER).debug("keep:%s [%d => %d]" % (str(keep), receivedAck, lAck[channel]))
|
|
|
|
|
if keep:
|
|
|
|
|
lAck[channel] = nextSentPacket
|
|
|
|
|
logging.getLogger(LOGGER).debug("lAck:%s" % ':'.join([str(x) for x in lAck]))
|
|
|
|
|
pass
|
|
|
|
|
num += 1
|
|
|
|
|
#actionFactory = CAction.CActionFactory(None)
|
|
|
|
|
action = self.actionFactory.unpack(msgin)
|
|
|
|
|
logging.getLogger(LOGGER).debug("action:%s" % action)
|
|
|
|
|
#action = self._CActionFactory.unpack(msgin)
|
|
|
|
|
if keep:
|
|
|
|
|
logging.getLogger(LOGGER).debug("keep Code:%s" % str(action.Code))
|
|
|
|
|
actions.append(action)
|
|
|
|
|
elif action:
|
|
|
|
|
logging.getLogger(LOGGER).debug("append Code:%s" % str(action.Code))
|
|
|
|
|
self.add_registered_action(clientid, action)
|
|
|
|
|
return actions
|
|
|
|
|
|
2019-11-06 13:13:23 +00:00
|
|
|
# def decode_client_receive_normal_message(self, msgin, clientid, dst):
|
|
|
|
|
# actions = self.client_state[clientid]['CImpulseDecoder'].decode(msgin, self.client_state[clientid]['CurrentReceivedNumber'], self.client_state[clientid]['LastReceivedAck'], self.client_state[clientid]['CurrentSendNumber'] )
|
2019-11-06 20:36:42 +00:00
|
|
|
# logging.getLogger(LOGGER).info("[Client -> Server] actions:%s" % str(actions))
|
2019-11-06 13:13:23 +00:00
|
|
|
# # decodeVisualProperties( msgin );
|
2019-10-24 17:45:24 +00:00
|
|
|
|
2019-11-06 13:13:23 +00:00
|
|
|
def decode_client_send_normal_message(self, msgin, clientid, dst):
|
|
|
|
|
'''
|
|
|
|
|
khanat-opennel-code/code/ryzom/client/src/network_connection.cpp:2029 void CNetworkConnection::sendNormalMessage()
|
|
|
|
|
khanat-opennel-code/code/ryzom/common/src/game_share/action_block.cpp:36 void CActionBlock::serial(CBitMemStream &msg)
|
|
|
|
|
'''
|
|
|
|
|
#actions = self.client_state[clientid]['CImpulseDecoder'].decode(msgin, self.client_state[clientid]['CurrentReceivedNumber'], self.client_state[clientid]['LastReceivedAck'], self.client_state[clientid]['CurrentSendNumber'] )
|
|
|
|
|
actions = []
|
|
|
|
|
noerror = True
|
|
|
|
|
msgin.disable_LogErrorOnStreamOverflow()
|
|
|
|
|
while noerror:
|
|
|
|
|
try:
|
|
|
|
|
cycle = msgin.readUint32("Cycle")
|
|
|
|
|
num = msgin.readUint8("num")
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Client -> Server] Cycle:%u num:%u" % (cycle, num))
|
2019-11-06 13:13:23 +00:00
|
|
|
for i in range(0, num):
|
|
|
|
|
actions.append(self.client_state[clientid]['CActionFactory'].unpack(msgin))
|
|
|
|
|
pass
|
|
|
|
|
except BitStream.OverflowError:
|
|
|
|
|
noerror = False
|
|
|
|
|
except Exception as e:
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Client -> Server] end %s (not read:%u)" % (e.__class__, msgin.needRead()))
|
2019-11-06 13:13:23 +00:00
|
|
|
raise e
|
|
|
|
|
msgin.enable_LogErrorOnStreamOverflow()
|
|
|
|
|
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Client -> Server] detail actions [%d] => %s" % ( len(actions), ', '.join([str(x) for x in actions])))
|
2019-11-06 13:13:23 +00:00
|
|
|
# decodeVisualProperties( msgin );
|
2019-10-24 17:45:24 +00:00
|
|
|
|
2019-11-06 20:36:42 +00:00
|
|
|
def decode_client_message(self, msgin, clientid, dst, sequenceid):
|
2019-10-24 17:45:24 +00:00
|
|
|
CurrentReceivedNumber = msgin.readSint32('CurrentReceivedNumber')
|
|
|
|
|
SystemMode = msgin.readBool('SystemMode')
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Client -> Server] {CurrentReceivedNumber:%d, SystemMode:%d, src:%s, dst:%s}" % (CurrentReceivedNumber, SystemMode, clientid, dst))
|
2019-10-24 17:45:24 +00:00
|
|
|
self.initialize_client(clientid)
|
|
|
|
|
self.client_state[clientid]['CurrentReceivedNumber'] = CurrentReceivedNumber
|
|
|
|
|
if not SystemMode:
|
2019-11-03 12:42:13 +00:00
|
|
|
'''
|
|
|
|
|
khanat-opennel-code/code/ryzom/client/src/network_connection.cpp:2029 void CNetworkConnection::sendNormalMessage()
|
|
|
|
|
'''
|
2019-10-24 17:45:24 +00:00
|
|
|
LastReceivedAck = msgin.readSint32('LastReceivedAck')
|
|
|
|
|
self.client_state[clientid]['LastReceivedAck'] = LastReceivedAck
|
2019-11-03 12:42:13 +00:00
|
|
|
AckBitMask = msgin.readUint32('AckBitMask')
|
|
|
|
|
self.client_state[clientid]['AckBitMask'] = AckBitMask
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Client -> Server] Normal Mode {CurrentReceivedNumber:%d, src:%s, dst:%s, LastReceivedAck:%d}" % (CurrentReceivedNumber, clientid, dst, LastReceivedAck))
|
2019-10-24 17:45:24 +00:00
|
|
|
#self.decode_server(msgin, _CurrentReceivedNumber, _CurrentReceivedNumber-1)
|
2019-11-06 13:13:23 +00:00
|
|
|
self.decode_client_send_normal_message(msgin, clientid, dst)
|
2019-10-24 17:45:24 +00:00
|
|
|
else:
|
|
|
|
|
message = msgin.readUint8('message')
|
|
|
|
|
try:
|
|
|
|
|
typeMessage = Enum.CLFECOMMON(message).name
|
|
|
|
|
except ValueError:
|
|
|
|
|
typeMessage = "Unknown"
|
|
|
|
|
if message == Enum.CLFECOMMON.SYSTEM_LOGIN_CODE:
|
|
|
|
|
UserAddr = msgin.readUint32('UserAddr')
|
|
|
|
|
UserKey = msgin.readUint32('UserKey')
|
|
|
|
|
UserId = msgin.readUint32('UserId')
|
|
|
|
|
LanguageCode = msgin.readString('LanguageCode')
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Client -> Server] System Mode:%s {CurrentReceivedNumber:%d, src:%s, dst:%s, UserAddr:%d, UserId:%d, UserAddr:%d LanguageCode:%s}" %
|
2019-10-24 17:45:24 +00:00
|
|
|
(typeMessage, CurrentReceivedNumber, clientid, dst, UserAddr, UserKey, UserId, LanguageCode))
|
|
|
|
|
elif message == Enum.CLFECOMMON.SYSTEM_PROBE_CODE:
|
|
|
|
|
LatestProbe = msgin.readSint32('LatestProbe')
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Client -> Server] System Mode:%s probe:%d {CurrentReceivedNumber:%d, src:%s, dst:%s}" % (typeMessage,
|
2019-10-24 17:45:24 +00:00
|
|
|
LatestProbe, CurrentReceivedNumber, clientid, dst))
|
|
|
|
|
elif message == Enum.CLFECOMMON.SYSTEM_SYNC_CODE:
|
|
|
|
|
Synchronize = msgin.readUint32('Synchronize')
|
|
|
|
|
stime = msgin.readSint64('stime')
|
|
|
|
|
LatestSync = msgin.readUint32('LatestSync')
|
|
|
|
|
MsgData = msgin.readArrayUint8(16, 'MsgData')
|
|
|
|
|
md5Msg = bytes(MsgData)
|
|
|
|
|
DatabaseData = msgin.readArrayUint8(16, 'DatabaseData')
|
|
|
|
|
md5Database = bytes(DatabaseData)
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Client -> Server] System Mode:%s {CurrentReceivedNumber:%d, src:%s, dst:%s, Synchronize:%d, stime:%d, LatestSync:%d, MsgData:%s, DatabaseData:%s}" % (
|
2019-10-24 17:45:24 +00:00
|
|
|
typeMessage, CurrentReceivedNumber, clientid, dst, Synchronize, stime, LatestSync, binascii.hexlify(md5Msg).decode(), binascii.hexlify(md5Database).decode()))
|
|
|
|
|
elif message == Enum.CLFECOMMON.SYSTEM_ACK_SYNC_CODE:
|
|
|
|
|
LastReceivedNumber = msgin.readSint32('LastReceivedNumber')
|
|
|
|
|
LastAckInLongAck = msgin.readSint32('LastAckInLongAck')
|
|
|
|
|
LongAckBitField = CBitSet.CBitSet()
|
|
|
|
|
LongAckBitField.readSerial(msgin, 'LongAckBitField')
|
|
|
|
|
LatestSync = msgin.readSint32('LatestSync')
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Client -> Server] System Mode:%s {CurrentReceivedNumber:%d, src:%s, dst:%s, LastReceivedNumber:%d, LastAckInLongAck:%d, LatestSync:%d, LongAckBitField:%s}" % (
|
2019-10-24 17:45:24 +00:00
|
|
|
typeMessage, CurrentReceivedNumber, clientid, dst, LastReceivedNumber, LastAckInLongAck, LatestSync, LongAckBitField))
|
|
|
|
|
elif message == Enum.CLFECOMMON.SYSTEM_ACK_PROBE_CODE:
|
|
|
|
|
SizeLatestProbes = msgin.readSint32('SizeLatestProbes')
|
|
|
|
|
LatestProbes = []
|
|
|
|
|
for data in range(0, SizeLatestProbes):
|
|
|
|
|
LatestProbes.append(msgin.readSint32('LatestProbes'))
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Client -> Server] System Mode:%s (%d) {CurrentReceivedNumber:%d, src:%s, dst:%s, SizeLatestProbes:%d, LatestProbes:%s}" % (typeMessage, message, CurrentReceivedNumber, clientid, dst, SizeLatestProbes, str(LatestProbes)))
|
2019-10-24 17:45:24 +00:00
|
|
|
else:
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Client -> Server] System Mode:%s (%d) {CurrentReceivedNumber:%d, src:%s, dst:%s}" % (typeMessage, message, CurrentReceivedNumber, clientid, dst))
|
|
|
|
|
logging.getLogger(LOGGER).debug("[Client -> Server] msg:%s" % msgin.showAllData())
|
2019-10-24 17:45:24 +00:00
|
|
|
|
2019-11-06 20:36:42 +00:00
|
|
|
def decode_khanat_message(self, msgin, src, dst, sequenceid):
|
2019-10-24 17:45:24 +00:00
|
|
|
CurrentSendNumber = msgin.readSint32('CurrentSendNumber')
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Server -> Client] {CurrentSendNumber:%d, src:%s, dst:%s}" % (CurrentSendNumber, src, dst))
|
2019-10-24 17:45:24 +00:00
|
|
|
SystemMode = msgin.readBool('SystemMode')
|
|
|
|
|
self.initialize_client(dst)
|
|
|
|
|
self.client_state[dst]['CurrentSendNumber'] = CurrentSendNumber
|
|
|
|
|
if not SystemMode:
|
|
|
|
|
_LastReceivedAck = msgin.readSint32('LastReceivedAck');
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Server -> Client] Normal Mode {CurrentSendNumber:%d, src:%s, dst:%s, _LastReceivedAck:%d}" % (CurrentSendNumber, src, dst, _LastReceivedAck))
|
2019-10-24 17:45:24 +00:00
|
|
|
actions = self.decode_server(dst, msgin, CurrentSendNumber, CurrentSendNumber-1)
|
|
|
|
|
if actions:
|
|
|
|
|
logging.getLogger(LOGGER).debug('list actions: [' + str(len(actions)) + '] ' +','.join( [ str(x) for x in actions] ) )
|
|
|
|
|
else:
|
|
|
|
|
logging.getLogger(LOGGER).debug('list actions: None')
|
|
|
|
|
|
|
|
|
|
# Decode the actions received in the impulsions
|
|
|
|
|
logging.getLogger(LOGGER).debug('=' * 80)
|
|
|
|
|
for action in actions:
|
|
|
|
|
logging.getLogger(LOGGER).debug('-' * 80)
|
|
|
|
|
logging.getLogger(LOGGER).debug('Analyse actions:%s', action)
|
|
|
|
|
if action.Code == Enum.TActionCode.ACTION_DISCONNECTION_CODE:
|
|
|
|
|
logging.getLogger(LOGGER).info("Action : ACTION_DISCONNECTION_CODE")
|
|
|
|
|
elif action.Code == Enum.TActionCode.ACTION_GENERIC_CODE:
|
|
|
|
|
action.genericAction(self.decodeImpulse, self.client_state[dst]['world'], self.client_state[dst]['GenericMultiPartTemp'])
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Server -> Client] ACTION_GENERIC_CODE : {CurrentSendNumber:%d, src:%s, dst:%s, _LastReceivedAck:%d, action:%s}" % (CurrentSendNumber, src, dst, _LastReceivedAck, action))
|
2019-10-24 17:45:24 +00:00
|
|
|
elif action.Code == Enum.TActionCode.ACTION_GENERIC_MULTI_PART_CODE:
|
|
|
|
|
action.genericAction(self.decodeImpulse, self.client_state[dst]['world'], self.client_state[dst]['GenericMultiPartTemp'])
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Server -> Client] ACTION_GENERIC_MULTI_PART_CODE : %s" % action)
|
2019-10-24 17:45:24 +00:00
|
|
|
for id in self.client_state[dst]['GenericMultiPartTemp'].data:
|
|
|
|
|
if self.client_state[dst]['GenericMultiPartTemp'].data[id].isAvailable():
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Server -> Client] ACTION_GENERIC_MULTI_PART_CODE {CurrentSendNumber:%d, src:%s, dst:%s, _LastReceivedAck:%d, id:%d, msg:%s}" % (CurrentSendNumber, src, dst, _LastReceivedAck, id, self.client_state[dst]['GenericMultiPartTemp'].data[id].read().showAllData()))
|
2019-10-24 17:45:24 +00:00
|
|
|
elif action.Code == Enum.TActionCode.ACTION_DUMMY_CODE:
|
|
|
|
|
logging.getLogger(LOGGER).info("Action : ACTION_DUMMY_CODE")
|
|
|
|
|
self.add_registered_action(dst, action)
|
|
|
|
|
# # remove all old actions that are acked
|
|
|
|
|
# while self._Actions and self._Actions[0].FirstPacket != 0 and self._Actions[0].FirstPacket < self._LastReceivedAck:
|
|
|
|
|
# logging.getLogger(LOGGER).debug("remove old action [%d/%d] : %s" % (self._Actions[0].FirstPacket, self._LastReceivedAck, self._Actions[0]))
|
|
|
|
|
# self._Actions.pop(0)
|
|
|
|
|
else:
|
|
|
|
|
message = msgin.readUint8('message')
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Server -> Client] System Mode {CurrentSendNumber:%d, src:%s, dst:%s, message:%d" % (CurrentSendNumber, src, dst, message))
|
2019-10-24 17:45:24 +00:00
|
|
|
if message == Enum.CLFECOMMON.SYSTEM_SYNC_CODE:
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Server -> Client] Synchronize")
|
2019-10-24 17:45:24 +00:00
|
|
|
Synchronize = msgin.readUint32('Synchronize')
|
|
|
|
|
stime = msgin.readSint64('stime')
|
|
|
|
|
LatestSync = msgin.readUint32('LatestSync')
|
|
|
|
|
MsgData = msgin.readArrayUint8(16, 'MsgData')
|
|
|
|
|
DatabaseData = msgin.readArrayUint8(16, 'DatabaseData')
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Server -> Client] System Mode / Synchronize {CurrentSendNumber:%d, src:%s, dst:%s, message:%d, Synchronize:%d, stime:%d, LatestSync:%d, MsgData:%s, DatabaseData:%s}" % (CurrentSendNumber, src, dst, message, Synchronize, stime, LatestSync, str(MsgData), str(DatabaseData)))
|
2019-10-24 17:45:24 +00:00
|
|
|
elif message == Enum.CLFECOMMON.SYSTEM_STALLED_CODE:
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Server -> Client] Stalled")
|
|
|
|
|
logging.getLogger(LOGGER).info("[Server -> Client] System Mode / Stalled {CurrentSendNumber:%d, src:%s, dst:%s, message:%d}" % (CurrentSendNumber, src, dst, message))
|
2019-10-24 17:45:24 +00:00
|
|
|
elif message == Enum.CLFECOMMON.SYSTEM_PROBE_CODE:
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Server -> Client] Probe")
|
2019-10-24 17:45:24 +00:00
|
|
|
LatestProbe = msgin.readSint32('LatestProbe')
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Server -> Client] System Mode / Probe {CurrentSendNumber:%d, src:%s, dst:%s, message:%d, LatestProbe:%d}" % (CurrentSendNumber, src, dst, message, LatestProbe))
|
2019-10-24 17:45:24 +00:00
|
|
|
elif message == Enum.CLFECOMMON.SYSTEM_SERVER_DOWN_CODE:
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).info("[Server -> Client] System Mode / BACK-END DOWN {CurrentSendNumber:%d, src:%s, dst:%s, message:%d}" % (CurrentSendNumber, src, dst, message))
|
2019-10-24 17:45:24 +00:00
|
|
|
else:
|
|
|
|
|
logging.getLogger(LOGGER).warning("CNET: received system %d in state Login" % message)
|
|
|
|
|
#cActionFactory = CAction.CActionFactory(None)
|
|
|
|
|
#cActionFactory.unpack(msgin)
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[Server -> Client] msg:%s" % msgin.showAllData())
|
2019-10-24 17:45:24 +00:00
|
|
|
|
|
|
|
|
def read(self):
|
|
|
|
|
file = open( self.pcap_file , 'rb')
|
|
|
|
|
pcapfile = savefile.load_savefile(file,verbose=False)
|
|
|
|
|
khanat_host = self.detect_khanat_server(pcapfile.packets)
|
2019-11-06 20:36:42 +00:00
|
|
|
clientid = 1
|
|
|
|
|
serverid = 1
|
|
|
|
|
list_host = {}
|
|
|
|
|
sequenceid = 1
|
|
|
|
|
|
2019-10-24 17:45:24 +00:00
|
|
|
for pkt in pcapfile.packets:
|
|
|
|
|
eth_frame = ethernet.Ethernet(pkt.raw())
|
|
|
|
|
if eth_frame.type == 2048:
|
|
|
|
|
ip_packet = ip.IP(binascii.unhexlify(eth_frame.payload))
|
|
|
|
|
if ip_packet.p == 17:
|
|
|
|
|
# UDP
|
|
|
|
|
udp_packet = udp.UDP(binascii.unhexlify(ip_packet.payload))
|
|
|
|
|
data = udp_packet.payload
|
|
|
|
|
if udp_packet.src_port == 53 or udp_packet.dst_port == 53:
|
|
|
|
|
continue
|
|
|
|
|
if not self.filter_host_service or self.filter_host_service.match("%s:%d" % (ip_packet.src.decode(), udp_packet.src_port)) or self.filter_host_service.match("%s:%d" % (ip_packet.dst.decode(), udp_packet.dst_port)):
|
|
|
|
|
logging.getLogger(LOGGER).debug("-" * 80)
|
|
|
|
|
if self.show_raw_packet:
|
2019-11-03 12:42:13 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[raw packet] timestamp:%s [%s] src:%s:%d dst:%s:%d data:%s" % (pkt.timestamp,
|
|
|
|
|
datetime.fromtimestamp(pkt.timestamp).strftime("%Y/%m/%d %H:%M:%S"),
|
2019-10-24 17:45:24 +00:00
|
|
|
ip_packet.src.decode(), udp_packet.src_port,
|
|
|
|
|
ip_packet.dst.decode(), udp_packet.dst_port,
|
|
|
|
|
data.decode()))
|
|
|
|
|
msgin = BitStream.BitStream()
|
|
|
|
|
msgin.fromBytes(binascii.unhexlify(data))
|
|
|
|
|
src = "%s:%d" % (ip_packet.src.decode(), udp_packet.src_port)
|
|
|
|
|
dst = "%s:%d" % (ip_packet.dst.decode(), udp_packet.dst_port)
|
2019-11-03 12:42:13 +00:00
|
|
|
|
2019-10-24 17:45:24 +00:00
|
|
|
if (self.khanat_host_service and self.khanat_host_service.match(src)) or ( not self.khanat_host_service and khanat_host == src):
|
2019-11-06 20:36:42 +00:00
|
|
|
_provenance = 'Server -> Client'
|
|
|
|
|
who = "Server"
|
|
|
|
|
if src not in list_host:
|
|
|
|
|
clientname = "Server %d" % serverid
|
|
|
|
|
list_host.setdefault(src, clientname)
|
|
|
|
|
serverid += 1
|
2019-11-03 12:42:13 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[%s] (message received) [%s] %s" % (_provenance, datetime.fromtimestamp(pkt.timestamp).strftime("%Y/%m/%d %H:%M:%S"), msgin.showAllData()))
|
2019-11-06 20:36:42 +00:00
|
|
|
self.decode_khanat_message(msgin, src, dst, sequenceid)
|
2019-10-24 17:45:24 +00:00
|
|
|
else:
|
2019-11-06 20:36:42 +00:00
|
|
|
_provenance = 'Client -> Server'
|
|
|
|
|
if src not in list_host:
|
|
|
|
|
clientname = "Client %d" % clientid
|
|
|
|
|
list_host.setdefault(src, clientname)
|
|
|
|
|
clientid += 1
|
|
|
|
|
who = "Client"
|
2019-11-03 12:42:13 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[%s] (message received) [%s] %s" % (_provenance, datetime.fromtimestamp(pkt.timestamp).strftime("%Y/%m/%d %H:%M:%S"), msgin.showAllData()))
|
2019-11-06 20:36:42 +00:00
|
|
|
self.decode_client_message(msgin, src, dst, sequenceid)
|
|
|
|
|
moredata='message decoded'
|
|
|
|
|
if not msgin.checkOnlyZeroAtEnd(): # msgin.needRead() > 7:
|
|
|
|
|
moredata = "message partially decoded"
|
2019-10-24 17:45:24 +00:00
|
|
|
if self.show_message_decoded:
|
2019-11-06 20:36:42 +00:00
|
|
|
logging.getLogger(LOGGER).debug("[%s] (%s) %s" % (_provenance, moredata, msgin.showAllData()))
|
|
|
|
|
if self.outyaml:
|
|
|
|
|
self.outyaml.write("\nmessage_%d:\n sequence: %d\n time: %s\n name: %s\n function: %s\n source: %s\n destination: %s\n state: %s\n message:\n" % (
|
|
|
|
|
sequenceid,
|
|
|
|
|
sequenceid,
|
|
|
|
|
datetime.fromtimestamp(pkt.timestamp).strftime("%Y/%m/%d %H:%M:%S"),
|
|
|
|
|
list_host[src],
|
|
|
|
|
who,
|
|
|
|
|
src,
|
|
|
|
|
dst,
|
|
|
|
|
moredata
|
|
|
|
|
))
|
|
|
|
|
for key in msgin.extractAllData():
|
|
|
|
|
self.outyaml.write(" - %s\n" % key)
|
|
|
|
|
sequenceid += 1
|
2019-10-24 17:45:24 +00:00
|
|
|
for client in self.client_state:
|
|
|
|
|
logging.getLogger(LOGGER).debug("%s [server tick:%d, client tick:%d]" %(client, self.client_state[client]['CurrentSendNumber'], self.client_state[client]['CurrentReceivedNumber']))
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
def main():
|
|
|
|
|
FORMAT = '%(asctime)-15s %(levelname)s %(filename)s:%(lineno)d %(message)s'
|
|
|
|
|
logging.basicConfig(format=FORMAT)
|
|
|
|
|
|
|
|
|
|
logger = []
|
|
|
|
|
logger.append(logging.getLogger(LOGGER))
|
|
|
|
|
logger.append(logging.getLogger(CImpulseDecoder.LOGGER))
|
|
|
|
|
#logger.append(logging.getLogger(DecodeImpuls.LOGGER))
|
|
|
|
|
#logger.append(logging.getLogger(BitStream.LOGGER))
|
|
|
|
|
logger.append(logging.getLogger(CStringManager.LOGGER))
|
|
|
|
|
logger.append(logging.getLogger(CAction.LOGGER))
|
|
|
|
|
logger.append(logging.getLogger(CActionFactory.LOGGER))
|
2019-11-06 13:13:23 +00:00
|
|
|
logger.append(logging.getLogger(BitStream.LOGGER))
|
2019-10-24 17:45:24 +00:00
|
|
|
CImpulseDecoder
|
|
|
|
|
# logger.append(logging.getLogger('CGenericMultiPartTemp'))
|
|
|
|
|
|
|
|
|
|
parser = argparse.ArgumentParser()
|
|
|
|
|
parser.add_argument("--khanat-host-service", help="filter to detect khanat host:service (FES)")
|
|
|
|
|
parser.add_argument("--filter-host-service", help="filter host:service")
|
|
|
|
|
parser.add_argument("-d", "--debug", help="show debug message", action='store_true')
|
2019-11-06 20:36:42 +00:00
|
|
|
parser.add_argument("-v", "--verbose", help="show verbose message", action='store_true')
|
2019-10-24 17:45:24 +00:00
|
|
|
parser.add_argument("-p", "--pcap-file", help="file pcap to read", required=True)
|
|
|
|
|
parser.add_argument("-m", "--msg-xml", help="file msg.xml (from server khanat)", required=True)
|
|
|
|
|
parser.add_argument("-r", "--raw", help="show message raw", action='store_true')
|
2019-11-06 20:36:42 +00:00
|
|
|
parser.add_argument("--yaml", help="generate YAML file (decode all message)", type=argparse.FileType('w'), default=None)
|
2019-10-24 17:45:24 +00:00
|
|
|
parser.add_argument("--show-raw-packet", help="show packet (raw data)", action='store_true')
|
|
|
|
|
parser.add_argument("--show-message-decoded", help="show packet (raw data)", action='store_true')
|
|
|
|
|
|
|
|
|
|
args = parser.parse_args()
|
|
|
|
|
|
|
|
|
|
if args.debug:
|
|
|
|
|
level = logging.getLevelName('DEBUG')
|
2019-11-06 20:36:42 +00:00
|
|
|
elif args.verbose:
|
2019-10-24 17:45:24 +00:00
|
|
|
level = logging.getLevelName('INFO')
|
2019-11-06 20:36:42 +00:00
|
|
|
else:
|
|
|
|
|
level = logging.getLevelName('WARNING')
|
|
|
|
|
|
2019-10-24 17:45:24 +00:00
|
|
|
|
|
|
|
|
for logid in logger:
|
|
|
|
|
logid.setLevel(level)
|
|
|
|
|
logging.getLogger(LOGGER).info("Begin")
|
|
|
|
|
|
2019-11-06 20:36:42 +00:00
|
|
|
spy = SpyPcap(khanat_host_service=args.khanat_host_service,
|
|
|
|
|
pcap_file=args.pcap_file,
|
|
|
|
|
msg_xml=args.msg_xml,
|
|
|
|
|
filter_host_service=args.filter_host_service,
|
|
|
|
|
show_raw_packet=args.show_raw_packet,
|
|
|
|
|
show_message_decoded=args.show_message_decoded,
|
|
|
|
|
outyaml=args.yaml)
|
2019-10-24 17:45:24 +00:00
|
|
|
if args.raw:
|
|
|
|
|
spy.readRaw()
|
|
|
|
|
else:
|
|
|
|
|
spy.read()
|
|
|
|
|
logging.getLogger(LOGGER).info("End")
|
|
|
|
|
|
|
|
|
|
if __name__ == "__main__":
|
|
|
|
|
main()
|
