#!/usr/bin/python3 # -*- coding: utf-8 -*- # # module ClientNetworkConnection # # 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 . import logging import sys import signal import socket import time import xml.etree.ElementTree as ET import hashlib from tools import CGenericMultiPartTemp from tools import Enum from tools import CBitSet from tools import World from tools import CImpulseDecoder from tools import DecodeImpulse from tools import TStampQueue from tools import BitStream from tools import CodeMsgXml from tools import CAction from tools import CActionFactory LOGGER='ClientNetworkConnection' def getTextMD5(dataRawXml): dataNew = '' for data in dataRawXml: if data != '\r': # '\015' ignore caractère \r\n => dataNew += data else: logging.getLogger(LOGGER).debug("***** data:%d" % (ord(data))) m = hashlib.md5() m.update(dataNew.encode('utf-8')) #print(m.hexdigest()) #print(m.digest()) return m.digest() class ClientNetworkConnection: ''' Partie client de la gestion de la communication reseau avec le serveur: client : code/ryzom/client/src/network_connection.cpp server : khanat-opennel-code/code/ryzom/server/src/frontend_service/fe_receive_sub.cpp # void CFeReceiveSub::handleReceivedMsg( CClientHost *clienthost ) ''' def __init__(self, khanat_host, khanat_port_frontend, headAccount, LanguageCode="fr", checkMessageNumber = True): self._CurrentSendNumber = 0 self.GenericMsgHeaderMngr = {} self.GenericMultiPartTemp = CGenericMultiPartTemp.GenericMultiPartTemp() self.LanguageCode = LanguageCode self._QuitId = 0 self._ConnectionState = Enum.TConnectionState.NotInitialised self.UserAddr, self.UserKey, self.UserId = None, None, None self.frontend = (khanat_host, khanat_port_frontend) self._sock = None self._CurrentReceivedNumber = 0 self._SystemMode = 0 self._LastReceivedAck = 0 self._LastReceivedNumber = 0 self._LastAckInLongAck = 0 self._MsgXmlMD5 = None self._DatabaseXmlMD5 = None self.msgXml = None self.databaseXml = None self._Synchronize = 0 self._LatestSync = 0 self._CurrentServerTick = 0 self._MsPerTick = 0 self._LCT = 100 self._UpdateTime = 0 #self._UpdateTicks = 0 self._ReceivedSync = False self._LastReceivedTime = 0 self._LastReceivedPacketInBothModes = 0 self._TotalMessages = 0 self._TotalLostPackets = 0 self.checkMessageNumber = checkMessageNumber self._LastAckBit = 0 self._AckBitMask = 0 self._LongAckBitField = CBitSet.CBitSet() self._LatestSyncTime = 0 self.headAccount = headAccount self.world = World.World() self._ImpulseDecoder = CImpulseDecoder.CImpulseDecoder(self.world) self._LongAckBitField.resize(1024) self._LatestProbeTime = 0 self._LatestProbe = 0 self._LatestProbes = [] self._LatestQuitTime = 0 self._ReceivedAckQuit = False self._Actions = [] self._PacketStamps = [] self.decodeImpulse = DecodeImpulse.DecodeImpulse() self._InstantPing = 0 self._BestPing = 10000 self._MsPerTick = 100 self._LastSendTime = 0 self._ImpulseMultiPartNumber = 0 self.clientTick = 0 self.stepAction = 0 def signal_exit(self, sig, frame): logging.getLogger(LOGGER).warning("Receive signal to quit program") self.sendSystemQuit() sys.exit(0) def connect(self): signal.signal(signal.SIGINT, self.signal_exit) signal.signal(signal.SIGTERM, self.signal_exit) try: self._sock = socket.socket(socket.AF_INET, # Internet socket.SOCK_DGRAM) # UDP except: logging.getLogger(LOGGER).error("Impossible to connect on khanat") return False self._ConnectionState = Enum.TConnectionState.Login self._LatestSyncTime = int(time.clock_gettime(1)*1000) return True def cookiesInit(self, UserAddr, UserKey, UserId): self.UserAddr = UserAddr self.UserKey = UserKey self.UserId = UserId def reset(self): self._CurrentSendNumber += 0 def buildSystemHeader(self, msgout): # code/ryzom/client/src/network_connection.cpp # void CNetworkConnection::buildSystemHeader(NLMISC::CBitMemStream &msgout) msgout.pushSint32(self._CurrentSendNumber) systemMode = True msgout.pushBool(systemMode) self._PacketStamps.append( TStampQueue.TStampQueue(self._CurrentSendNumber, self._UpdateTime) ) self._CurrentSendNumber += 1 def sendSystemLogin(self): # code/ryzom/client/src/network_connection.cpp # void CNetworkConnection::sendSystemLogin() logging.getLogger(LOGGER).debug("sendSystemLogin") if self._sock is None: raise ValueError msgout = BitStream.BitStream() self.buildSystemHeader(msgout) msgout.pushUint8(Enum.CLFECOMMON.SYSTEM_LOGIN_CODE) msgout.pushUint32(self.UserAddr) msgout.pushUint32(self.UserKey) msgout.pushUint32(self.UserId) msgout.pushString(self.LanguageCode) logging.getLogger(LOGGER).debug("sendSystemLogin:%s" % msgout.showAllDataWrite()) self._sock.sendto(msgout.toBytes(), self.frontend) self._CurrentSendNumber += 1 self._ConnectionState = Enum.TConnectionState.Login def sendSystemQuit(self): # code/ryzom/client/src/network_connection.cpp # void CNetworkConnection::sendSystemQuit() logging.getLogger(LOGGER).debug("sendSystemQuit") # Disconnect if self._sock is None: raise ValueError self._QuitId += 1 msgout = BitStream.BitStream() self.buildSystemHeader(msgout) msgout.pushUint8(Enum.CLFECOMMON.SYSTEM_QUIT_CODE) msgout.pushSint32(self._QuitId) logging.getLogger(LOGGER).debug("sendSystemQuit:%s" % msgout.showAllDataWrite()) self._sock.sendto(msgout.toBytes(), self.frontend) self._ConnectionState = Enum.TConnectionState.Quit def sendSystemAckSync(self): ''' code/ryzom/client/src/network_connection.cpp # void CNetworkConnection::sendSystemAckSync() ''' logging.getLogger(LOGGER).debug("sendSystemAckSync _LastReceivedNumber:%d _LastAckInLongAck:%d _LatestSync:%d" % (self._LastReceivedNumber, self._LastAckInLongAck, self._LatestSync)) msgout = BitStream.BitStream() self.buildSystemHeader(msgout) msgout.pushUint8(Enum.CLFECOMMON.SYSTEM_ACK_SYNC_CODE) msgout.pushSint32(self._LastReceivedNumber) msgout.pushSint32(self._LastAckInLongAck) self._LongAckBitField.writeSerial(msgout) msgout.pushSint32(self._LatestSync) logging.getLogger(LOGGER).debug("sendSystemAckSync:%s" % msgout.showAllDataWrite()) self._sock.sendto(msgout.toBytes(), self.frontend) self._LatestSyncTime = self._UpdateTime def sendSystemAckProbe(self): logging.getLogger(LOGGER).debug("sendSystemAckProbe") msgout = BitStream.BitStream() self.buildSystemHeader(msgout) msgout.pushUint8(Enum.CLFECOMMON.SYSTEM_ACK_PROBE_CODE) msgout.pushSint32(len(self._LatestProbes)) for data in self._LatestProbes: msgout.pushSint32(data) self._LatestProbes = [] logging.getLogger(LOGGER).debug("sendSystemAckProbe:%s" % msgout.showAllDataWrite()) self._sock.sendto(msgout.toBytes(), self.frontend) def sendSystemDisconnection(self): logging.getLogger(LOGGER).debug("sendSystemDisconnection") if self._sock is None: raise ValueError msgout = BitStream.BitStream() self.buildSystemHeader(msgout) msgout.pushUint8(Enum.CLFECOMMON.SYSTEM_DISCONNECTION_CODE) self._sock.sendto(msgout.toBytes(), self.frontend) def sendStringRequest(self, stringId): # Launch query for StringID (we will rfeceived the full text # khanat-opennel-code/code/ryzom/client/src/string_manager_client.cpp:333 bool CStringManagerClient::getString(uint32 stringId, ucstring &result) # Send STRING_MANAGER:STRING_RQ logging.getLogger(LOGGER).debug("sendStringRequest") if self._sock is None: raise ValueError msgout = BitStream.BitStream() ref = CodeMsgXml.CodeMsgXml(self.msgXml, 'STRING_MANAGER:STRING_RQ') for size, value, id in ref: msgout.internalSerial(value, size, typeName=id) msgout.pushUint32(stringId) self.push(msgout) def sendNormalMessage(self): ''' khanat-opennel-code/code/ryzom/client/src/network_connection.cpp # void CNetworkConnection::sendNormalMessage() ''' logging.getLogger(LOGGER).debug("sendNormalMessage") if self._sock is None: raise ValueError msgout = BitStream.BitStream() msgout.pushSint32(self._CurrentSendNumber) systemMode = False # Normal msgout.pushBool(systemMode) msgout.pushSint32(self._LastReceivedNumber) msgout.pushSint32(self._AckBitMask) numPacked = 0 for block in self._Actions: if block.Cycle == 0: break if block.FirstPacket == 0: block.FirstPacket = self._CurrentSendNumber; block.writeSerial(msgout) numPacked += 1 if msgout.getPosInBit() > 480*8: # easy version break logging.getLogger(LOGGER).debug("Send:%s" % msgout.showAllDataWrite()) self._sock.sendto(msgout.toBytes(), self.frontend) self._LastSendTime = int(time.clock_gettime(1)*1000) self._PacketStamps.append( TStampQueue.TStampQueue(self._CurrentSendNumber, self._UpdateTime) ) self._CurrentSendNumber += 1 def readDelta(self, msg): propertyCount = msg.readUint16('propertyCount') logging.getLogger(LOGGER).debug("propertyCount:%d" % propertyCount) logging.getLogger(LOGGER).debug("TODO") for _ in range(0, propertyCount): pass def buildStream(self, buffersize=65536): # khanat-opennel-code/code/ryzom/client/src/network_connection.cpp # bool CNetworkConnection::buildStream( CBitMemStream &msgin ) data, addr = self._sock.recvfrom(buffersize) return data, addr def decodeHeader(self, msg): ''' khanat-opennel-code/code/ryzom/client/src/network_connection.cpp # bool CNetworkConnection::decodeHeader(CBitMemStream &msgin, bool checkMessageNumber) ''' self._TotalMessages += 1 self._LastReceivedTime = self._UpdateTime self._CurrentReceivedNumber = msg.readSint32('CurrentReceivedNumber') self._SystemMode = msg.readBool('SystemMode') if self.checkMessageNumber and self._CurrentReceivedNumber > self._LastReceivedPacketInBothModes: self._TotalLostPackets += self._CurrentReceivedNumber - self._LastReceivedPacketInBothModes - 1 self._LastReceivedPacketInBothModes = self._CurrentReceivedNumber # else: # self._LastReceivedPacketInBothModes = self._CurrentReceivedNumber - 1 if not self._SystemMode: self._LastReceivedAck = msg.readSint32('LastReceivedAck'); logging.getLogger(LOGGER).debug("Normal Mode _LastReceivedAck:%d" % self._LastReceivedAck) else: logging.getLogger(LOGGER).debug("System Mode") if self._CurrentReceivedNumber > self._LastReceivedNumber+1: logging.getLogger(LOGGER).debug("lost messages server->client [%d; %d]" %(self._LastReceivedPacketInBothModes + 1, self._CurrentReceivedNumber - 1)) elif self._CurrentReceivedNumber == self._LastReceivedNumber: logging.getLogger(LOGGER).debug("awaiting packet %d, received packet %d" %(self._LastReceivedPacketInBothModes + 1, self._CurrentReceivedNumber)) return False elif self._CurrentReceivedNumber < self._LastReceivedNumber: logging.getLogger(LOGGER).debug("received an old message, awaiting packet %d, received packet %d" %(self._LastReceivedPacketInBothModes + 1, self._CurrentReceivedNumber)) return False ackBool = ( not self._SystemMode ) and (self._ConnectionState == Enum.TConnectionState.Connected or self._ConnectionState == Enum.TConnectionState.Synchronize) if ackBool: ackBit = 1 else: ackBit = 0 if self._CurrentReceivedNumber - self._LastReceivedNumber < 32: self._AckBitMask <<= self._CurrentReceivedNumber - self._LastReceivedNumber self._AckBitMask |= self._LastAckBit << (self._CurrentReceivedNumber - self._LastReceivedNumber - 1) elif (self._CurrentReceivedNumber - self._LastReceivedNumber) == 32 and self._LastAckBit != 0: self._AckBitMask = 0x80000000 else: self._AckBitMask = 0x00000000 self._LastAckBit = ackBit; for i in range(self._LastReceivedNumber+1, self._CurrentReceivedNumber): self._LongAckBitField.clearBit(i & 511) # (512 - 1) mask 9bit self._LongAckBitField.set(self._CurrentReceivedNumber & 511, ackBool) # (512 - 1) mask 9bit logging.getLogger(LOGGER).debug("_LastAckInLongAck:%d _CurrentReceivedNumber:%d" % (self._LastAckInLongAck, self._CurrentReceivedNumber)) if self._LastAckInLongAck <= (self._CurrentReceivedNumber-512): self._LastAckInLongAck = self._CurrentReceivedNumber-511; # (512 - 1) mask 9bit self._LastReceivedNumber = self._CurrentReceivedNumber logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d, _LastReceivedNumber:%d, ackBit:%d, _AckBitMask:%d _LongAckBitField:%s" % (self._CurrentReceivedNumber, self._LastReceivedNumber, ackBit, self._AckBitMask, self._LongAckBitField)) return True def receiveSystemProbe(self, msg): logging.getLogger(LOGGER).debug("receiveSystemProbe") self._LatestProbeTime = self._UpdateTime self._LatestProbe = msg.readSint32('LatestProbe') logging.getLogger(LOGGER).debug("LatestProbe: %d" % self._LatestProbe) self._LatestProbes.append(self._LatestProbe) logging.getLogger(LOGGER).debug("Msg Received:" + msg.showAllData()) def receiveSystemStalled(self, msg): logging.getLogger(LOGGER).debug("received STALLED") logging.getLogger(LOGGER).debug("Msg Received:" + msg.showAllData()) def receiveSystemSync(self, msg): logging.getLogger(LOGGER).debug("receiveSystemSync") self._LatestSyncTime = self._UpdateTime self._Synchronize = msg.readUint32('Synchronize') stime = msg.readSint64('stime') self._LatestSync = msg.readUint32('LatestSync') logging.getLogger(LOGGER).debug("%d %d %d" %(self._Synchronize, stime, self._LatestSync)) # khanat-opennel-code/code/ryzom/client/src/network_connection.cpp : void CNetworkConnection::receiveSystemSync(CBitMemStream &msgin) MsgData = msg.readArrayUint8(16, 'MsgData') DatabaseData = msg.readArrayUint8(16, 'DatabaseData') logging.getLogger(LOGGER).debug("MsgData:" + str(MsgData)) logging.getLogger(LOGGER).debug("DatabaseData:" + str(DatabaseData)) md5Msg = bytes(MsgData) md5Database = bytes(DatabaseData) if md5Msg == self._MsgXmlMD5: logging.getLogger(LOGGER).info("Check MD5 msg.xml : OK") else: logging.getLogger(LOGGER).error("Check MD5 msg.xml : KO") if md5Database == self._DatabaseXmlMD5: logging.getLogger(LOGGER).info("Check MD5 database.xml : OK") else: logging.getLogger(LOGGER).error("Check MD5 database.xml : KO") logging.getLogger(LOGGER).debug("Msg Received:" + msg.showAllData()) self._MsPerTick = 100 self._CurrentServerTick = self._Synchronize + self._CurrentReceivedNumber + 2 self._CurrentClientTick = self._CurrentServerTick - ( self._LCT + self._MsPerTick ) / self._MsPerTick self._CurrentClientTime = self._UpdateTime - (self._LCT + self._MsPerTick) self.sendSystemAckSync() def decodeVisualProperties(self, msgin): ''' khanat-opennel-code/code/ryzom/client/src/network_connection.cpp # void CNetworkConnection::decodeVisualProperties( CBitMemStream& msgin ) ''' while True: if msgin.getPosInBit() + 8*8 > len(msgin)*8: return slot = msgin.readUint8('slot') associationBits = msgin.readUint32('associationBits') logging.getLogger(LOGGER).debug("slot:%d associationBits:%d" %(slot, associationBits)) logging.getLogger(LOGGER).debug("TODO") return def receiveNormalMessage(self, msgin): logging.getLogger(LOGGER).debug("receiveNormalMessage : received normal message Packet (%d) %s" % (msgin.needRead(), msgin.showLastData() )) actions = self._ImpulseDecoder.decode(msgin, self._CurrentReceivedNumber, self._LastReceivedAck, self._CurrentSendNumber ) if actions: logging.getLogger(LOGGER).debug('actions: ' +','.join( [ str(x) for x in actions] ) ) else: logging.getLogger(LOGGER).debug('actions: None') logging.getLogger(LOGGER).debug("Message not read (%d) %s" % (msgin.needRead(), msgin.showLastData() )) # 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) self._CurrentServerTick = self._CurrentReceivedNumber * 2 + self._Synchronize # remove useless stamps in queue while len(self._PacketStamps) != 0 and self._LastReceivedAck > self._PacketStamps[0].first: self._PacketStamps.pop(0) # Statistique ! if len(self._PacketStamps) == 0 or self._PacketStamps[0].first > self._LastReceivedAck: pass else: ackedPacketTime = self._PacketStamps[0].second ping = self._UpdateTime - ackedPacketTime self._InstantPing = ping if ping < self._BestPing: self._BestPing = ping earliest = ackedPacketTime + self._BestPing//2 latest = self._UpdateTime - self._BestPing//2 numStepTick = self._CurrentServerTick - self._CurrentClientTick if numStepTick > 0 and earliest > self._CurrentClientTime and latest > self._CurrentClientTime: if self._CurrentClientTime + self._MsPerTick * numStepTick < earliest: self._MsPerTick = (earliest - self._CurrentClientTime)//numStepTick if (self._CurrentClientTime + self._MsPerTick * numStepTick) > latest: self._MsPerTick = (latest - self._CurrentClientTime)//numStepTick if self._MsPerTick == 0: logging.getLogger(LOGGER).warning("_MsPerTick is 0 because server tick is too big %d compare to the client tick is %d" %(self._CurrentServerTick, self._CurrentClientTick)) self._MsPerTick = 1 elif numStepTick <= 0: self._MsPerTick = self._LCT ## remove useless stamps in queue #while self._PacketStamps and self._LastReceivedAck > self._PacketStamps[0].first: # self._PacketStamps.pop(0) 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) if action.Code == Enum.TActionCode.ACTION_DISCONNECTION_CODE: logging.getLogger(LOGGER).debug("Action : ACTION_DISCONNECTION_CODE") self.disconnect() elif action.Code == Enum.TActionCode.ACTION_GENERIC_CODE: logging.getLogger(LOGGER).debug("Action : ACTION_GENERIC_CODE") action.genericAction(self.decodeImpulse, self.world, self.GenericMultiPartTemp) logging.getLogger(LOGGER).info("Action: ACTION_GENERIC_CODE : %s" % action) elif action.Code == Enum.TActionCode.ACTION_GENERIC_MULTI_PART_CODE: logging.getLogger(LOGGER).debug("Action : ACTION_GENERIC_MULTI_PART_CODE") action.genericAction(self.decodeImpulse, self.world, self.GenericMultiPartTemp) elif action.Code == Enum.TActionCode.ACTION_DUMMY_CODE: logging.getLogger(LOGGER).debug("Action : ACTION_DUMMY_CODE") self._ImpulseDecoder.removeCAction(action) # Decode the visual properties self.decodeVisualProperties( msgin ); self._LastReceivedNormalTime = int(time.clock_gettime(1)*1000) logging.getLogger(LOGGER).debug("Msg Received:" + msgin.showAllData()) def receiveSystemAckQuit(self, msgin): logging.getLogger(LOGGER).debug("received ACK_QUIT") self._ReceivedAckQuit = True logging.getLogger(LOGGER).debug("Msg Received:" + msgin.showAllData()) def disconnect(self): logging.getLogger(LOGGER).info("Disconnect") self.sendSystemDisconnection() self._sock.close() self._sock = None self._ConnectionState = Enum.TConnectionState.Disconnect def stateLogin(self, msgin): self.decodeHeader(msgin) if self._SystemMode: message = msgin.readUint8('message') logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d]" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead())) if message == Enum.CLFECOMMON.SYSTEM_SYNC_CODE: self._ConnectionState = Enum.TConnectionState.Synchronize logging.getLogger(LOGGER).debug("Login->synchronize") self.receiveSystemSync(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_STALLED_CODE: logging.getLogger(LOGGER).debug("received STALLED") self._ConnectionState = Enum.TConnectionState.Stalled self.receiveSystemStalled(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_PROBE_CODE: logging.getLogger(LOGGER).debug("Login->probe") self._ConnectionState = Enum.TConnectionState.Probe self.receiveSystemProbe(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_SERVER_DOWN_CODE: self.disconnect() logging.getLogger(LOGGER).warning("BACK-END DOWN") return False else: logging.getLogger(LOGGER).warning("CNET: received system %d in state Login" % message) logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d] '%s'" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead(), msgin.showLastData())) else: logging.getLogger(LOGGER).warning("CNET: received normal in state Login") return False def stateSynchronize(self, msgin): logging.getLogger(LOGGER).debug("stateSynchronize") self.decodeHeader(msgin) if self._SystemMode: message = msgin.readUint8('message') logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d]" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead())) if message == Enum.CLFECOMMON.SYSTEM_PROBE_CODE: logging.getLogger(LOGGER).debug("synchronize->probe") self._ConnectionState = Enum.TConnectionState.Probe self.receiveSystemProbe(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_STALLED_CODE: logging.getLogger(LOGGER).debug("received STALLED") self._ConnectionState = Enum.TConnectionState.Stalled self.receiveSystemStalled(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_SYNC_CODE: logging.getLogger(LOGGER).debug("synchronize->synchronize") self.receiveSystemSync(msgin) elif message == Enum.CLFECOMMON.SYSTEM_SERVER_DOWN_CODE: self.disconnect() logging.getLogger(LOGGER).warning("BACK-END DOWN") return False else: logging.getLogger(LOGGER).warning("CNET: received system %d in state Synchronize" % message) logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d] '%s'" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead(), msgin.showLastData())) else: self._ConnectionState = Enum.TConnectionState.Connected logging.getLogger(LOGGER).warning("CNET: synchronize->connected") # _Changes.push_back(CChange(0, ConnectionReady)); self._ImpulseDecoder.reset(); self.receiveNormalMessage(msgin); return True logging.getLogger(LOGGER).debug("sendSystemAckSync ? (%d , %d , %d)" %(self._UpdateTime, self._LatestSyncTime, self._UpdateTime - self._LatestSyncTime)) if self._UpdateTime - self._LatestSyncTime > 300: self.sendSystemAckSync(); return False def stateConnected(self, msgin): self.decodeHeader(msgin) if self._SystemMode: message = msgin.readUint8('message') logging.getLogger(LOGGER).debug("SystemMode _CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d]" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead())) if message == Enum.CLFECOMMON.SYSTEM_PROBE_CODE: logging.getLogger(LOGGER).debug("Connected->probe") self._ConnectionState = Enum.TConnectionState.Probe self.receiveSystemProbe(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_SYNC_CODE: logging.getLogger(LOGGER).debug("Connected->synchronize") self.receiveSystemSync(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_STALLED_CODE: logging.getLogger(LOGGER).debug("received STALLED") self._ConnectionState = Enum.TConnectionState.Stalled self.receiveSystemStalled(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_SERVER_DOWN_CODE: self.disconnect() logging.getLogger(LOGGER).warning("BACK-END DOWN") return False else: logging.getLogger(LOGGER).warning("CNET: received system %d in state Connected" % message) logging.getLogger(LOGGER).debug("NormalMode _CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d] '%s'" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead(), msgin.showLastData())) else: self.receiveNormalMessage(msgin); return True return False def stateProbe(self, msgin): self.decodeHeader(msgin) if self._SystemMode: message = msgin.readUint8('message') logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d]" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead())) if message == Enum.CLFECOMMON.SYSTEM_SYNC_CODE: logging.getLogger(LOGGER).debug("probe->synchronize") self._ConnectionState = Enum.TConnectionState.Synchronize self.receiveSystemSync(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_STALLED_CODE: logging.getLogger(LOGGER).debug("probe->stalled") self._ConnectionState = Enum.TConnectionState.Stalled self.receiveSystemStalled(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_PROBE_CODE: self.receiveSystemProbe(msgin) elif message == Enum.CLFECOMMON.SYSTEM_SERVER_DOWN_CODE: self.disconnect() logging.getLogger(LOGGER).warning("BACK-END DOWN") return False else: logging.getLogger(LOGGER).warning("CNET: received system %d in state Probe" % message) logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d] '%s'" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead(), msgin.showLastData())) else: logging.getLogger(LOGGER).warning("received normal in state Probe") if (len(self._LatestProbes) > 0) or (self._UpdateTime - self._LatestProbeTime > 300): self.sendSystemAckProbe() self._LatestProbeTime = self._UpdateTime return False def stateStalled(self, msgin): self.decodeHeader(msgin) if self._SystemMode: message = msgin.readUint8('message') logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d]" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead())) if message == Enum.CLFECOMMON.SYSTEM_SYNC_CODE: logging.getLogger(LOGGER).debug("stalled->synchronize") self._ConnectionState = Enum.TConnectionState.Synchronize self.receiveSystemSync(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_PROBE_CODE: logging.getLogger(LOGGER).debug("stalled->probe") self._ConnectionState = Enum.TConnectionState.Probe self.receiveSystemProbe(msgin) elif message == Enum.CLFECOMMON.SYSTEM_STALLED_CODE: self.receiveSystemStalled(msgin) elif message == Enum.CLFECOMMON.SYSTEM_SERVER_DOWN_CODE: self.disconnect() logging.getLogger(LOGGER).warning("BACK-END DOWN") return False else: logging.getLogger(LOGGER).warning("CNET: received system %d in state Stalled" % message) logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d] '%s'" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead(), msgin.showLastData())) else: logging.getLogger(LOGGER).warning("received normal in state Stalled") return False def stateQuit(self, msgin): self.decodeHeader(msgin) if self._SystemMode: message = msgin.readUint8('message') logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d]" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead())) if message == Enum.CLFECOMMON.SYSTEM_SYNC_CODE: logging.getLogger(LOGGER).debug("quit->synchronize") self._ConnectionState = Enum.TConnectionState.Synchronize self.receiveSystemSync(msgin) return True elif message == Enum.CLFECOMMON.SYSTEM_SERVER_DOWN_CODE: self.disconnect() logging.getLogger(LOGGER).warning("BACK-END DOWN") return False elif message == Enum.CLFECOMMON.SYSTEM_ACK_QUIT_CODE: self.receiveSystemAckQuit(msgin) else: logging.getLogger(LOGGER).warning("CNET: received system %d in state Quit" % message) logging.getLogger(LOGGER).debug("_CurrentReceivedNumber:%d (mode:%s) %d [%d/%d/%d] '%s'" % (self._CurrentReceivedNumber, str(self._SystemMode), message, msgin.sizeData(), msgin.sizeRead(), msgin.needRead(), msgin.showLastData())) else: logging.getLogger(LOGGER).warning("received normal in state Quit") if not self._ReceivedAckQuit and (self._UpdateTime - self._LatestQuitTime > 100): self.sendSystemQuit() self._LatestQuitTime = self._UpdateTime return False def update(self): # khanat-opennel-code/code/ryzom/client/src/network_connection.cpp # bool CNetworkConnection::update() self._UpdateTime = int(time.clock_gettime(1)*1000) self._ReceivedSync = False if not self._sock: return False # TODO - REMOVE this counter (just to stop loop) counterLoop = 0 stateBroke = True while stateBroke: buffer, addr = self.buildStream() msgin = BitStream.BitStream() msgin.fromBytes(buffer) logging.getLogger(LOGGER).debug("received message: %s" % msgin.showAllData()) if self._ConnectionState == Enum.TConnectionState.Login: logging.getLogger(LOGGER).debug("state:Login") stateBroke = self.stateLogin(msgin) elif self._ConnectionState == Enum.TConnectionState.Synchronize: logging.getLogger(LOGGER).debug("state:Synchronize") stateBroke = self.stateSynchronize(msgin) elif self._ConnectionState == Enum.TConnectionState.Connected: logging.getLogger(LOGGER).debug("state:Connected") stateBroke = self.stateConnected(msgin) elif self._ConnectionState == Enum.TConnectionState.Probe: logging.getLogger(LOGGER).debug("state:Probe") stateBroke = self.stateProbe(msgin) elif self._ConnectionState == Enum.TConnectionState.Stalled: logging.getLogger(LOGGER).debug("state:Stalled") stateBroke = self.stateStalled(msgin) elif self._ConnectionState == Enum.TConnectionState.Quit: logging.getLogger(LOGGER).debug("state:Quit") stateBroke = self.stateQuit(msgin) else: stateBroke = False logging.getLogger(LOGGER).debug("message decoded: %s" % msgin.showAllData()) counterLoop += 1 if counterLoop > 10: break def push_back(self, action): ''' khanat-opennel-code/code/ryzom/client/src/network_connection.cpp # void CNetworkConnection::push(CAction *action) ''' # search to aggregate Action (send by block) if len(self._Actions) == 0 or self._Actions[-1].Cycle != 0: self._Actions.append(CAction.CActionBlock()) self._Actions[-1].push_back(action) def push(self, msgout): ''' khanat-opennel-code/code/ryzom/client/src/network_connection.cpp # void CNetworkConnection::push(CBitMemStream &msg) ''' logging.getLogger(LOGGER).debug("Push :%s" % msgout.showAllDataWrite()) maxImpulseBitSize = 1840 # = 230*8 cp = CActionFactory.CActionFactory(self.world) ag = cp.createFactory(CAction.INVALID_SLOT, Enum.TActionCode.ACTION_GENERIC_CODE) bytelen = (msgout.sizeData() + 7) // 8 impulseMinBitSize = ag.size() impulseBitSize = impulseMinBitSize + (4 + bytelen)*8 logging.getLogger(LOGGER).debug("maxImpulseBitSize:%d bytelen:%d impulseMinBitSize:%d impulseBitSize:%d" %(maxImpulseBitSize, bytelen, impulseMinBitSize, impulseBitSize)) if impulseBitSize < maxImpulseBitSize: ag.set(msgout); self.push_back(ag) else: agmp = cp.createFactory(CAction.INVALID_SLOT, Enum.TActionCode.ACTION_GENERIC_MULTI_PART_CODE) minimumBitSizeForMP = agmp.size() availableSize = (maxImpulseBitSize - minimumBitSizeForMP) // 8 nbBlock = (bytelen + availableSize - 1) // availableSize num = self._ImpulseMultiPartNumber self._ImpulseMultiPartNumber += 1 logging.getLogger(LOGGER).debug("minimumBitSizeForMP:%d availableSize:%d nbBlock:%d num:%d _ImpulseMultiPartNumber:%d" % (minimumBitSizeForMP, availableSize, nbBlock, num, self._ImpulseMultiPartNumber)) for i in range(0, nbBlock): logging.getLogger(LOGGER).debug("i:%d nbBlock:%d" % (i, nbBlock)) if i != 0: # Create a new CActionFactory agmp = cp.createFactory(CAction.INVALID_SLOT, Enum.TActionCode.ACTION_GENERIC_MULTI_PART_CODE) agmp.set(num, i, msgout.buffer(), bytelen, availableSize, nbBlock) self.push_back(agmp) def sendFastMode(self): if self._ConnectionState == Enum.TConnectionState.Connected and self._LastSendTime > 100: self.sendNormalMessage() def send(self): ''' khanat-opennel-code/code/ryzom/client/src/network_connection.cpp # void CNetworkConnection::send(TGameCycle cycle) ''' cycle = self._CurrentServerTick bitSize = 32*8 # block size is 32 (cycle) + 8 (number of actions if len(self._Actions) == 0 or self._Actions[-1].Cycle != 0: logging.getLogger(LOGGER).debug("No Action") pass else: logging.getLogger(LOGGER).debug("Prepare Action") block = self._Actions[-1] block.Cycle = cycle # check last block isn't bigger than maximum allowed i = 0 for action in block.Actions: bitSize += action.size() if bitSize >= 480*8: break i += 1 if i < len(self._Actions): # Too big block -> split block newBlock = CAction.CActionBlock() newBlock.Cylce = 0 newBlock.insert(self._Actions, i, len(block.Actions)) block.eraseToEnd(i) if self._ConnectionState == Enum.TConnectionState.Connected: self.sendNormalMessage() #if len(self.world.Commands) > 0: # cmd = self.world.Commands.pop(0) def analyze(self): for id, data in self.world.StringManager.unknown: logging.getLogger(LOGGER).debug("id:%d, data:%s" % (id, data.showAllData())) self.sendStringRequest(id) for id in self.world.StringManager.unknownParameterString: logging.getLogger(LOGGER).debug("id:%d" % (id)) self.sendStringRequest(id) for msg in self.world.StringManager.decoded: logging.getLogger(LOGGER).info("message:%s" % (msg)) self.world.StringManager.cleanDecodedMessage() if self.world.CurrentState == Enum.TState.st_connect: if self.world.CShardNames != []: if self.stepAction == 0 and self.world.CharacterSummaries != [] and self.clientTick > 0: if self.world.CharacterSummaries[0].People == Enum.TPeople.Unknown: bms = self.world.CreaterCharacter(self.msgXml, self.headAccount) self.push(bms) self.stepAction = 1 else: self.stepAction = 1 elif self.stepAction == 1 and self.world.CharacterSummaries != []: if self.world.CharacterSummaries[0].People != Enum.TPeople.Unknown: logging.getLogger(LOGGER).info("Account defined %s" % self.world.CharacterSummaries[0].Name) bms = self.world.SelectChar(self.msgXml, 0) self.push(bms) self.stepAction = 2 def EmulateFirst(self, msgRawXml, databaseRawXml): self.world.CurrentState = Enum.TState.st_start self.msgXml = ET.fromstring(msgRawXml) #ET.dump(msgXml) self.databaseXml = ET.fromstring(databaseRawXml) #ET.dump(databaseXml) self._MsgXmlMD5 = getTextMD5(msgRawXml) self._DatabaseXmlMD5 = getTextMD5(databaseRawXml) self.decodeImpulse.loadMsg(self.msgXml) self.decodeImpulse.loadDatabase(self.databaseXml) self.connect() logging.getLogger(LOGGER).info("Client Login") self.sendSystemLogin() self.world.CurrentState = Enum.TState.st_connect logging.getLogger(LOGGER).info("Receive Message") self.clientTick = 0 for _ in range(0, 50): #while True: logging.getLogger(LOGGER).debug("%s [%s: %d / %d] %s" % ("*" * 40, "Loop", self.clientTick, self.stepAction, "*" * 40)) self.update() self.analyze() self.send() self.clientTick += 1 logging.getLogger(LOGGER).info("Client Quit") self.sendSystemQuit()