diff --git a/config.json b/config.json index 69ef3bc..f0e239a 100644 --- a/config.json +++ b/config.json @@ -3,7 +3,6 @@ "logging": { "filename": "", "level": "DEBUG", - "format": "[%(name)s:L%(lineno)02d %(levelname)s] %(message)s", "datefmt": "%d-%b-%y %H:%M:%S" } }, diff --git a/notes/packetlist.txt b/notes/packetlist.txt index 5d1649e..f9c4c79 100644 --- a/notes/packetlist.txt +++ b/notes/packetlist.txt @@ -7,6 +7,6 @@ 0x1F ID_NO_FREE_INCOMING_CONNECTIONS 0x24 ID_CONNECTION_BANNED 0x25 ID_INVALID_PASSWORD +0x26 ID_MODIFIED_PACKET 0x27 ID_PONG 0x37 ID_ADVERTISE_SYSTEM -0x26 ID_MODIFIED_PACKET diff --git a/sampy/__init__.py b/sampy/__init__.py index 4787b85..d7dd39d 100644 --- a/sampy/__init__.py +++ b/sampy/__init__.py @@ -1,3 +1,5 @@ +from . import helpers + from . import server from . import client diff --git a/sampy/client/player.py b/sampy/client/player.py index 1a9bc1a..2a30e73 100644 --- a/sampy/client/player.py +++ b/sampy/client/player.py @@ -1,10 +1,12 @@ import socket import struct +from time import time_ns + from .base import BaseClient from ..raknet.bitstream import Bitstream -import logging +from ..helpers import logging logger = logging.getLogger(__name__) STATE_CONNECTING = 0 @@ -12,6 +14,9 @@ STATE_CONNECTED = 1 class PlayerClient(BaseClient): + ranges = [] + resend_list = dict() + def __init__(self, server: "__ServerInstance__", ip: str, port: int): super().__init__(server, ip, port) logger.debug("Client resolved to PlayerClient") @@ -74,50 +79,112 @@ class PlayerClient(BaseClient): async def on_player_packet(self, packet: bytes): bitstream = Bitstream(packet) + time = time_ns() _, has_acks = bitstream.read_bit() if has_acks: - logger.debug("Unfinished code hit; has_acks: True") - return + #logger.debug("Unfinished code hit; has_acks: True") + await self.handle_acknowledgement(bitstream, time) + #return handled = await self.handle_internal_packet(bitstream) if not handled: logger.debug("Internal packet were not handled") + + async def handle_acknowledgement(self, bitstream: Bitstream, time: int) -> bool: + if not self.deserialize(bitstream): + return False + for i in range(len(self.ranges)): + min, max = self.ranges[i][0], self.ranges[i][1] + if min > max: + return False + for i in range(min, max + 1, 1): + acked_histogram_counter = self.remove_packet_from_resend_list_and_delete_older_reliable_sequence() + + def deserialize(self, bitstream: Bitstream): # TODO: Something weird with range thing DS_RangeList.h@L92 + self.ranges.clear() + + success, count = bitstream.read_compressed(0x10, True) + if not success: + return False + + count, = struct.unpack(b" bool: - if (bitstream.length * 8) - bitstream.offset < 0x10: + if bitstream.length - bitstream.offset < 0x10: return False - _, message_number = bitstream.read(0x10) - _, reliability = bitstream.read_int(0x04) + _, message_number = bitstream.read_bits(0x10) + _, reliability = bitstream.read_bits(0x04) if reliability in (7, 9, 10): - success, ordering_channel = bitstream.read_int(0x05) - if success == False: + success, ordering_channel = bitstream.read_bits(0x05) + if not success: return False - success, ordering_index = bitstream.read_int(0x10) - if success == False: + success, ordering_index = bitstream.read_bits(0x10) + if not success: return False - _, is_split_packet = bitstream.read_bit() + _, is_split_packet = bitstream.read_bit() if is_split_packet: logger.warning("Skipping split packet") return + # TODO: set global split_packet index and count back to 0 + # Something I dont understand yet # TODO: ReadCompressed #bitstream.offset += 1 - _, data = bitstream.read_compressed(0x10, True) - _, unknown = bitstream.read(0x01) - _, bit_length = bitstream.read(0x08) + success, data_bit_length = bitstream.read_compressed(0x10, True) + if not success: + return False + + #_, unknown = bitstream.read(0x01) + #_, bit_length = bitstream.read(0x08) ## - logger.debug("bit_length: %d" % bit_length) - logger.debug("bitstream: %s" % bitstream) + #logger.debug("bit_length: %d" % bit_length) + #logger.debug("bitstream: %s" % bitstream) + + data_bit_length, = struct.unpack(b"> 3) - logger.debug("data: %s" % data) \ No newline at end of file + logger.debug("data: %s" % data) + + return await self.handle_packet(data) + + async def handle_packet(self, packet: bytes): + if packet[0] == 0x0B: # ID_CONNECTION_REQUEST + pass # TODO: Send ack and data after + return False \ No newline at end of file diff --git a/sampy/default_config.json b/sampy/default_config.json index ce7a8ea..ac8a6a9 100644 --- a/sampy/default_config.json +++ b/sampy/default_config.json @@ -3,7 +3,6 @@ "logging": { "filename": "", "level": "DEBUG", - "format": "[%(name)s:L%(lineno)02d %(levelname)s] %(message)s", "datefmt": "%d-%b-%y %H:%M:%S" } }, diff --git a/sampy/helpers/__init__.py b/sampy/helpers/__init__.py new file mode 100644 index 0000000..4d49c29 --- /dev/null +++ b/sampy/helpers/__init__.py @@ -0,0 +1 @@ +from . import logging \ No newline at end of file diff --git a/sampy/helpers/logging.py b/sampy/helpers/logging.py new file mode 100644 index 0000000..e966351 --- /dev/null +++ b/sampy/helpers/logging.py @@ -0,0 +1,62 @@ +import sys +import logging + +from logging import * + +if sys.platform == 'win32': + import colorama + colorama.init() + +FORMAT_STR_NORMAL = "%(levelname)s \x1b[33;1m%(asctime)s.%(msecs)03d \x1b[30;1m|\x1b[0m %(message)s" + +COLOR_RESET = 0 +COLOR_BLACK = 30 +COLOR_RED = 31 +COLOR_GREEN = 32 +COLOR_YELLOW = 33 +COLOR_BLUE = 34 +COLOR_PURPLE = 35 +COLOR_CYAN = 36 +COLOR_GRAY = 90 +COLOR_PINK = 95 + +COLOR_PREFIX = "\x1b[%dm" + +def color(color_code: int) -> str: + return COLOR_PREFIX % color_code + +def init(): + from ..shared import glob + + COLORS = { + logging.CRITICAL: "31", + logging.FATAL: "31", + logging.ERROR: "31", + logging.WARNING: "33", + logging.INFO: "32", + logging.DEBUG: "35", + logging.NOTSET: "37", + } + for k,v in COLORS.items(): + logging.addLevelName(k, "\x1b[%sm%s\x1b[0m" % (v, " " * (8 - len(logging.getLevelName(k))) + logging.getLevelName(k))) + + conf = glob.conf["logging"] + default_logging_fallback = False + if type(conf["level"]) is not int: + try: + conf["level"] = getattr(logging, conf["level"]) + except: + conf["level"] = logging.INFO + default_logging_fallback = True + + logging_handlers = [logging.StreamHandler(sys.stdout)] + if len(conf["filename"]): + logging_handlers.append(logging.FileHandler(conf["filename"])) + del conf["filename"] + logging.basicConfig(**conf, format=FORMAT_STR_NORMAL, handlers = logging_handlers) + + if default_logging_fallback: + logging.warning("Invalid logging value in config! Defaulting to logging level INFO.") + logging.info("Logging level: %d" % conf["level"]) + + logging.debug("Logger configured") diff --git a/sampy/raknet/bitstream.py b/sampy/raknet/bitstream.py index 876675e..c907a33 100644 --- a/sampy/raknet/bitstream.py +++ b/sampy/raknet/bitstream.py @@ -1,29 +1,109 @@ +from __future__ import annotations + import ctypes as c from array import array from typing import Tuple, Union -import logging +from ..helpers import logging logger = logging.getLogger(__name__) +DEBUG = (logger.root.level & logging.DEBUG) == 10 + +if DEBUG: + import inspect + +BITS_TO_BYTES = lambda x: (((x)+7)>>3) +BYTES_TO_BITS = lambda x: ((x)<<3) + +debug_wrapper_depth = 0 +ignored_bits = [] class Bitstream: def __init__(self, data: bytes = b""): self._offset = 0 self._buffer = bytearray(data) # array("B", data) + def debug_wrapper(func): + def wrapper(self, *args, **kwargs): + if not DEBUG: + return func(self, *args, **kwargs) + + global debug_wrapper_depth + #global ignored_bits + ignored_bits.clear() + + curframe = inspect.currentframe() + calframe = inspect.getouterframes(curframe, 2) + + #print(calframe) + + copy = self.clone() + + header_func = "%s%s" % (func.__name__, (*args, *kwargs)) + header = " {BLUE}{header_func}{SPACE_FUNC}{CYAN}{caller}{SPACE_CALLER}{GREEN}{file}{YELLOW}@L{lineno}{RESET}".format( + header_func = header_func, + caller = calframe[1].function, + file = calframe[1].filename.split("\\")[-1], + lineno = calframe[1].lineno, + CYAN = logging.color(logging.COLOR_CYAN), + BLUE = logging.color(logging.COLOR_BLUE), + GREEN = logging.color(logging.COLOR_GREEN), + YELLOW = logging.color(logging.COLOR_YELLOW), + RESET = logging.color(logging.COLOR_RESET), + SPACE_FUNC = " " * (28 - len(header_func)), + SPACE_CALLER = " " * (32 - len(calframe[1].function)), + ) + + prefix = "%s%s%s" % ( + logging.color(logging.COLOR_RED), + ">" * debug_wrapper_depth, + logging.color(logging.COLOR_RESET) + ) + logger.debug(prefix + header) + + debug_wrapper_depth += 1 + + result = func(self, *args, **kwargs) + edits = self.debug_edits(copy) + + debug_wrapper_depth -= 1 + + logger.debug(edits) + return result + return wrapper + @property def offset(self) -> int: return self._offset @property def length(self) -> int: - return len(self._buffer) + return len(self._buffer) << 3 + + def clone(self) -> Bitstream: + copy = Bitstream(self._buffer) + copy._offset = self._offset + return copy def _can_access_bits(self, bits_to_access: int) -> bool: return self._offset + bits_to_access <= len(self._buffer) << 3 + + def add_bits(self, bit_length: int): + if bit_length <= 0: + return + self._buffer.extend(b"\x00" * BITS_TO_BYTES(bit_length)) + + def align_read_to_byte_boundary(self): + if DEBUG: + ignored_from = self._offset + if self._offset: + self._offset += 8 - (((self._offset - 1) & 7) + 1) + if DEBUG: + ignored_bits.append((ignored_from, self._offset)) + @debug_wrapper def write_bit(self, value: bool) -> bool: if not self._can_access_bits(1): return False @@ -37,6 +117,7 @@ class Bitstream: self._offset += 1 return True + @debug_wrapper def read_bit(self) -> Tuple[bool, bool]: if not self._can_access_bits(1): return False, False @@ -47,6 +128,7 @@ class Bitstream: self._offset += 1 return True, value > 0 + @debug_wrapper def write(self, value: bytes, bit_length: int) -> bool: if not self._can_access_bits(bit_length): return False @@ -78,7 +160,8 @@ class Bitstream: self._buffer[byte_index] = byte return True - + + @debug_wrapper def read_int(self, bit_length: int) -> Tuple[bool, int]: if not self._can_access_bits(bit_length): return False, 0 @@ -111,6 +194,29 @@ class Bitstream: success, value = self.read_int(bit_length) return success, value.to_bytes((bit_length + 7) >> 3, "big") # bytes(value) + @debug_wrapper + def write_compressed(self, data: bytes, bit_length: int, unsigned: bool = True) -> bool: + current_byte = (bit_length >> 3) - 1 + byte_match = 0 if unsigned else 0xFF + + while current_byte > 0: + if data[current_byte] == byte_match: + self.write_bit(True) + else: + self.write_bit(False) + self.write_bits(data, (current_byte + 1) << 3, True) + return True + + if (unsigned and data[current_byte] & 0xF0 == 0x00) or (not unsigned and data[current_byte] & 0xF0 == 0xF0): + self.write_bit(True) + self.write_bits(data[current_byte:], 4, True) + else: + self.write_bit(False) + self.write_bits(data[current_byte:], 8, True) + + return True + + @debug_wrapper def read_compressed(self, bit_length: int, unsigned: bool = True) -> Tuple[bool, bytes]: current_byte = (bit_length >> 3) - 1 @@ -121,16 +227,16 @@ class Bitstream: while current_byte > 0: success, bit = self.read_bit() - if success == False: # Cannot read the bit (end of stream) + if not success: # Cannot read the bit (end of stream) return False, out if bit: out[current_byte] = byte_match current_byte -= 1 else: - success, data = self.read((current_byte + 1) << 3) - out[:current_byte] = data - if success == False: + success, data = self.read_bits((current_byte + 1) << 3, True) + out[:len(data)] = data + if not success: return False, out return True, out @@ -138,23 +244,102 @@ class Bitstream: return False, out success, bit = self.read_bit() - if success == False: # Cannot read the bit (end of stream) + if not success: # Cannot read the bit (end of stream) return False, out if bit: - success, data = self.read(4) - out[current_byte:current_byte + 4] = data - if success == False: + success, data = self.read_bits(4, True) + out[current_byte:((current_byte + 4) + 7) >> 3] = data + if not success: return False, out out[current_byte] |= half_byte_match # Maybe recheck this in BitStream.cpp@L617; We have to set the high 4 bits since these are set to 0 by ReadBits else: - success, data = self.read(8) + success, data = self.read_bits(8, True) out[current_byte:current_byte + 8] = data - if success == False: + if not success: return False, out return True, out + + @debug_wrapper + def write_bits(self, data: bytes, bit_length: int, align_bits_to_right: bool = True) -> bool: + if bit_length <= 0: + return False + + self.add_bits(bit_length) # TODO: Check if needed + + bits_used_mod8 = self.offset & 7 + + offset = 0 + while bit_length > 0: + byte = data[offset] + + if bit_length < 8 and align_bits_to_right: + byte <<= 8 - bit_length + + if bits_used_mod8 == 0: + self._buffer[self.offset >> 3] = byte + else: + self._buffer[self.offset >> 3] |= byte >> bits_used_mod8 + if 8 - bits_used_mod8 < 8 and 8 - bits_used_mod8 < bit_length: # Eh.. why not bits_used_mod8 != 0? + self._buffer[(self.offset >> 3) + 1] = byte << (8 - bits_used_mod8) + + if bit_length >= 8: + self._offset += 8 + else: + self._offset += bit_length + + bit_length -= 8 + offset += 1 + + return True + + @debug_wrapper + def read_bits(self, bit_length: int, align_bits_to_right: bool = True) -> Tuple[bool, bytes]: + if bit_length <= 0: + return False, b"" + if not self._can_access_bits(bit_length): + return False, b"" + + out = bytearray(BITS_TO_BYTES(bit_length)) + + read_offset_mod8 = self._offset & 7 + + offset = 0 + while bit_length > 0: + out[offset] |= (self._buffer[self._offset >> 3] << read_offset_mod8) & 255 + if read_offset_mod8 > 0 and bit_length > 8 - read_offset_mod8: + out[offset] |= self._buffer[(self.offset >> 3) + 1] >> (8 - read_offset_mod8) + + bit_length -= 8 + + if bit_length < 0: + if align_bits_to_right: + out[offset] >>= -bit_length + self._offset += 8 + bit_length + else: + self._offset += 8 + + offset += 1 + + return True, out + + @debug_wrapper + def read_aligned_bytes(self, byte_length: int) -> Tuple[bool, bytes]: + if byte_length <= 0: + return False, b"" + + self.align_read_to_byte_boundary() + + if self.offset + (byte_length << 3) > (len(self._buffer) << 3): + return False, b"" + + out = self._buffer[(self.offset >> 3):(self.offset >> 3) + byte_length] + + self._offset += byte_length << 3 + + return True, out def pretty(self) -> str: b = bytearray(" " + " ".join(" ".join(format(c, "08b")) for c in self._buffer) + " ", "ascii") @@ -162,5 +347,42 @@ class Bitstream: b[m] = 124 return b.decode() + def debug_edits(self, prev_state: Bitstream) -> str: + #logger.debug(self.pretty()) + + bits = [list(format(c, "08b")) for c in self._buffer] + prev_bits = [list(format(c, "08b")) for c in prev_state._buffer] + + bits.append([]) + + start = prev_state._offset + end = self._offset + + edits = {start: "P", end: "R"} + + for s, e in ignored_bits: + t = [x for x in edits.keys() if x <= s] + if len(t): + edits[e] = edits[t[-1]] + else: + edits[e] = "R" + edits[s] = "S" + + edits = sorted(edits.items()) + edits.reverse() + for k, v in edits: + bits[k // 8][k % 8:k % 8] = v + + #print(bits) + + bits = " ".join("".join([y + " " if y in "01" else y for y in x]).strip() for x in bits) + + bits = bits.replace("R", logging.color(logging.COLOR_RESET)) + bits = bits.replace("P", logging.color(logging.COLOR_PINK)) + bits = bits.replace("S", logging.color(logging.COLOR_RED)) + + + return bits + def __repr__(self) -> str: return "" % (id(self), self._offset, len(self._buffer) << 3) diff --git a/sampy/shared/glob.py b/sampy/shared/glob.py index 413240f..c5a98bc 100644 --- a/sampy/shared/glob.py +++ b/sampy/shared/glob.py @@ -2,7 +2,8 @@ import os import sys import json import shutil -import logging + +from ..helpers import logging if not os.path.isfile("config.json"): shutil.copyfile(os.path.join(*__package__.split(".")[:-1], "default_config.json"), "config.json") @@ -14,27 +15,4 @@ with open("config.json", "r") as f: conf = config["sampy"] conf_log = conf["logging"] -# Setup logger -## fix for logging level -default_logging_fallback = False -if type(conf_log["level"]) is not int: - try: - conf_log["level"] = getattr(logging, conf_log["level"]) - except Exception: - conf_log["level"] = logging.INFO - default_logging_fallback = True - -## logging settings -logging_handlers = [logging.StreamHandler(sys.stdout)] -if len(conf_log["filename"]): - logging_handlers.append(logging.FileHandler(conf_log["filename"])) -del conf_log["filename"] -logging.basicConfig(**conf_log, handlers = logging_handlers) - -logger = logging.getLogger(__name__) - -logger.debug("Configured logger") - -if default_logging_fallback: - logger.warning("Invalid logging value in config! Defaulting to logging level INFO.") -logger.info("Logging level: %d" % conf_log["level"]) +logging.init() \ No newline at end of file diff --git a/test.py b/test.py index 459aee3..6b44857 100644 --- a/test.py +++ b/test.py @@ -1,85 +1,128 @@ from sampy.raknet.bitstream import Bitstream +from sampy.client.player import PlayerClient -bitstream = Bitstream(b"\x00" * 4) -MAGIC_BYTES = b"\x01\xff\x02" -MAGIC_BITS = [int(bit) for bit in " ".join([format(byte, "08b") for byte in MAGIC_BYTES]) if bit in ("0", "1")] -fail = 0 +import struct -def print_pretty(prefix, msg): - prefix += " " * (40 - len(prefix)) - print(prefix, msg) +class Packet: + def __init__(self, data: bytes, is_client: bool): + self.data = data + self.is_client = is_client + self.bitstream = Bitstream(bytearray.fromhex(self.data)) -def reset_bitstream(): - bitstream._buffer = bytearray(b"\x00" * len(bitstream._buffer)) - bitstream._offset = 0 +PACKETS = [ + Packet("18 69 69", True), + Packet("1a 18 be", False), + Packet("18 71 d7", True), + Packet("19 00", False), + Packet("00 00 43 80 0b", True), + Packet("e3 00 00", False), + Packet("00 00 42 98 0c 11 33 30 45 39 33 39 33 33 36 39 42 35 36 38 43 32 00", False) +] -def test_write_bit(var_bits): - global fail - print_pretty("", bitstream.pretty()) - for bit in var_bits: - if not bitstream.write_bit(bit): - print_pretty("", "Failed") - fail += 1 - print_pretty("", bitstream.pretty()) +#client = PlayerClient(None, "127.0.0.1", 7777) +#client.state = 1 -def test_read_bit(var_compare_bits): - global fail - print_pretty("", bitstream.pretty()) - for bit in var_compare_bits: - ok, bit2 = bitstream.read_bit() - if not ok: - print_pretty("", "Failed (ok)") - fail += 1 - continue - if bit2 != bit: - print_pretty("", "Failed (match)") - fail += 1 - continue - print_pretty("", bitstream.pretty()) +def pbs(bitstream: Bitstream, prefix: str = ""): + print(prefix, bitstream.pretty()) -def test_write(var_bytes): - global fail - print_pretty("", bitstream.pretty()) - if not bitstream.write(var_bytes, len(var_bytes) << 3): - print_pretty("", "Failed") - fail += 1 - print_pretty("", bitstream.pretty()) +def deserialize(bitstream: Bitstream): # TODO: Something weird with range thing DS_RangeList.h@L92 + success, count = bitstream.read_compressed(0x10, True) + if not success: + return False + + count, = struct.unpack(b"", bitstream.pretty()) - ok, bytez = bitstream.read(len(var_compare_bytes) << 3) - if ok: - print(var_compare_bytes, bytez) - if bytez != var_compare_bytes: - print_pretty("", "Failed (match)") - fail += 1 - else: - print_pretty("", "Failed (ok)") - fail += 1 - print_pretty("", bitstream.pretty()) + min, max = 0, 0 + for i in range(count): + _, max_equal_to_min = bitstream.read_bit() + success, min = bitstream.read_bits(0x10) + if not success: + return False + + min, = struct.unpack(b" bool: + if bitstream.length - bitstream.offset < 0x10: + return False -print("Failed: %d" % fail) \ No newline at end of file + _, message_number = bitstream.read_bits(0x10) + pbs(bitstream, "message_number") + _, reliability = bitstream.read_bits(0x04) + pbs(bitstream, "reliability") + + if reliability in (7, 9, 10): + success, ordering_channel = bitstream.read_bits(0x05) + pbs(bitstream, "ordering_channel") + if not success: + return False + success, ordering_index = bitstream.read_bits(0x10) + pbs(bitstream, "ordering_index") + if not success: + return False + + _, is_split_packet = bitstream.read_bit() + pbs(bitstream, "is_split_packet") + + if is_split_packet: + print("Skipping split packet") + return + + # TODO: set global split_packet index and count back to 0 + + # Something I dont understand yet + # TODO: ReadCompressed + #bitstream.offset += 1 + success, data_bit_length = bitstream.read_compressed(0x10, True) + pbs(bitstream, "data_bit_length") + if not success: + return False + + #_, unknown = bitstream.read(0x01) + #_, bit_length = bitstream.read(0x08) + ## + + #logger.debug("bit_length: %d" % bit_length) + #logger.debug("bitstream: %s" % bitstream) + + data_bit_length, = struct.unpack(b"> 3) + pbs(bitstream, "data") + + print("data: %s" % data) + +on_player_packet(PACKETS[-2].bitstream._buffer) \ No newline at end of file