artemis/core/aimedb.py

411 lines
17 KiB
Python
Raw Normal View History

import logging, coloredlogs
from Crypto.Cipher import AES
2024-01-09 08:07:04 +00:00
from typing import Dict, Tuple, Callable, Union, Optional
import asyncio
from logging.handlers import TimedRotatingFileHandler
from core.config import CoreConfig
2023-11-29 23:01:19 +00:00
from core.utils import create_sega_auth_key
from core.data import Data
from .adb_handlers import *
2024-01-09 08:07:04 +00:00
class AimedbServlette():
request_list: Dict[int, Tuple[Callable[[bytes, int], Union[ADBBaseResponse, bytes]], int, str]] = {}
2024-01-09 08:07:04 +00:00
def __init__(self, core_cfg: CoreConfig) -> None:
self.config = core_cfg
self.data = Data(core_cfg)
self.logger = logging.getLogger("aimedb")
2024-01-09 08:07:04 +00:00
if not hasattr(self.logger, "initted"):
log_fmt_str = "[%(asctime)s] Aimedb | %(levelname)s | %(message)s"
log_fmt = logging.Formatter(log_fmt_str)
fileHandler = TimedRotatingFileHandler(
"{0}/{1}.log".format(self.config.server.log_dir, "aimedb"),
when="d",
backupCount=10,
)
fileHandler.setFormatter(log_fmt)
consoleHandler = logging.StreamHandler()
consoleHandler.setFormatter(log_fmt)
self.logger.addHandler(fileHandler)
self.logger.addHandler(consoleHandler)
self.logger.setLevel(self.config.aimedb.loglevel)
coloredlogs.install(
level=core_cfg.aimedb.loglevel, logger=self.logger, fmt=log_fmt_str
)
self.logger.initted = True
if not core_cfg.aimedb.key:
self.logger.error("!!!KEY NOT SET!!!")
exit(1)
2023-03-09 16:38:58 +00:00
self.register_handler(0x01, 0x03, self.handle_felica_lookup, 'felica_lookup')
self.register_handler(0x02, 0x03, self.handle_felica_register, 'felica_register')
self.register_handler(0x04, 0x06, self.handle_lookup, 'lookup')
self.register_handler(0x05, 0x06, self.handle_register, 'register')
self.register_handler(0x07, 0x08, self.handle_status_log, 'status_log')
self.register_handler(0x09, 0x0A, self.handle_log, 'aime_log')
self.register_handler(0x0B, 0x0C, self.handle_campaign, 'campaign')
self.register_handler(0x0D, 0x0E, self.handle_campaign_clear, 'campaign_clear')
self.register_handler(0x0F, 0x10, self.handle_lookup_ex, 'lookup_ex')
self.register_handler(0x11, 0x12, self.handle_felica_lookup_ex, 'felica_lookup_ex')
self.register_handler(0x13, 0x14, self.handle_log_ex, 'aime_log_ex')
self.register_handler(0x64, 0x65, self.handle_hello, 'hello')
2024-01-09 08:07:04 +00:00
def register_handler(self, cmd: int, resp:int, handler: Callable[[bytes, int], Union[ADBBaseResponse, bytes]], name: str) -> None:
self.request_list[cmd] = (handler, resp, name)
2024-01-09 08:07:04 +00:00
def start(self) -> None:
self.logger.info(f"Start on port {self.config.aimedb.port}")
2024-01-14 21:48:41 +00:00
addr = self.config.aimedb.listen_address if self.config.aimedb.listen_address else self.config.server.listen_address
asyncio.create_task(asyncio.start_server(self.dataReceived, addr, self.config.aimedb.port))
2024-01-09 08:07:04 +00:00
async def dataReceived(self, reader: asyncio.StreamReader, writer: asyncio.StreamWriter):
self.logger.debug(f"Connection made from {writer.get_extra_info('peername')[0]}")
while True:
try:
2024-01-09 08:16:31 +00:00
data: bytes = await reader.read(4096)
2024-01-09 08:07:04 +00:00
if len(data) == 0:
self.logger.debug("Connection closed")
return
await self.process_data(data, reader, writer)
await writer.drain()
except ConnectionResetError as e:
2024-01-09 08:17:23 +00:00
self.logger.debug("Connection reset, disconnecting")
2024-01-09 08:07:04 +00:00
return
async def process_data(self, data: bytes, reader: asyncio.StreamReader, writer: asyncio.StreamWriter) -> Optional[bytes]:
addr = writer.get_extra_info('peername')[0]
cipher = AES.new(self.config.aimedb.key.encode(), AES.MODE_ECB)
try:
decrypted = cipher.decrypt(data)
except Exception as e:
self.logger.error(f"Failed to decrypt {data.hex()} because {e}")
2024-01-09 08:07:04 +00:00
return
2024-01-09 08:07:04 +00:00
self.logger.debug(f"{addr} wrote {decrypted.hex()}")
try:
head = ADBHeader.from_data(decrypted)
except ADBHeaderException as e:
self.logger.error(f"Error parsing ADB header: {e}")
try:
encrypted = cipher.encrypt(ADBBaseResponse().make())
2024-01-09 08:07:04 +00:00
writer.write(encrypted)
await writer.drain()
return
except Exception as e:
self.logger.error(f"Failed to encrypt default response because {e}")
return
if head.keychip_id == "ABCD1234567" or head.store_id == 0xfff0:
self.logger.warning(f"Request from uninitialized AMLib: {vars(head)}")
2024-01-09 08:07:04 +00:00
if head.cmd == 0x66:
self.logger.info("Goodbye")
writer.close()
return
handler, resp_code, name = self.request_list.get(head.cmd, (self.handle_default, None, 'default'))
if resp_code is None:
self.logger.warning(f"No handler for cmd {hex(head.cmd)}")
elif resp_code > 0:
2024-01-09 08:07:04 +00:00
self.logger.info(f"{name} from {head.keychip_id} ({head.game_id}) @ {addr}")
2024-01-09 08:07:04 +00:00
resp = await handler(decrypted, resp_code)
if type(resp) == ADBBaseResponse or issubclass(type(resp), ADBBaseResponse):
resp_bytes = resp.make()
elif type(resp) == bytes:
resp_bytes = resp
elif resp is None: # Nothing to send, probably a goodbye
2024-01-09 08:07:04 +00:00
self.logger.warn(f"None return by handler for {name}")
return
else:
2024-01-09 08:07:04 +00:00
self.logger.error(f"Unsupported type returned by ADB handler for {name}: {type(resp)}")
raise TypeError(f"Unsupported type returned by ADB handler for {name}: {type(resp)}")
2024-01-09 08:07:04 +00:00
try:
encrypted = cipher.encrypt(resp_bytes)
self.logger.debug(f"Response {resp_bytes.hex()}")
2024-01-09 08:07:04 +00:00
writer.write(encrypted)
except Exception as e:
self.logger.error(f"Failed to encrypt {resp_bytes.hex()} because {e}")
2024-01-09 08:07:04 +00:00
async def handle_default(self, data: bytes, resp_code: int, length: int = 0x20) -> ADBBaseResponse:
req = ADBHeader.from_data(data)
2023-08-19 05:35:37 +00:00
return ADBBaseResponse(resp_code, length, 1, req.game_id, req.store_id, req.keychip_id, req.protocol_ver)
2024-01-09 08:07:04 +00:00
async def handle_hello(self, data: bytes, resp_code: int) -> ADBBaseResponse:
return await self.handle_default(data, resp_code)
2023-03-09 16:38:58 +00:00
2024-01-09 08:07:04 +00:00
async def handle_campaign(self, data: bytes, resp_code: int) -> ADBBaseResponse:
h = ADBHeader.from_data(data)
if h.protocol_ver >= 0x3030:
req = h
2023-08-19 05:35:37 +00:00
resp = ADBCampaignResponse.from_req(req)
2023-03-09 16:38:58 +00:00
else:
req = ADBOldCampaignRequest(data)
self.logger.info(f"Legacy campaign request for campaign {req.campaign_id} (protocol version {hex(h.protocol_ver)})")
2023-08-19 05:35:37 +00:00
resp = ADBOldCampaignResponse.from_req(req.head)
# We don't currently support campaigns
return resp
2024-01-09 08:07:04 +00:00
async def handle_lookup(self, data: bytes, resp_code: int) -> ADBBaseResponse:
req = ADBLookupRequest(data)
2024-01-09 19:42:17 +00:00
user_id = await self.data.card.get_user_id_from_card(req.access_code)
is_banned = await self.data.card.get_card_banned(req.access_code)
is_locked = await self.data.card.get_card_locked(req.access_code)
2024-01-09 08:07:04 +00:00
ret = ADBLookupResponse.from_req(req.head, user_id)
if is_banned and is_locked:
ret.head.status = ADBStatus.BAN_SYS_USER
elif is_banned:
ret.head.status = ADBStatus.BAN_SYS
elif is_locked:
ret.head.status = ADBStatus.LOCK_USER
self.logger.info(
f"access_code {req.access_code} -> user_id {ret.user_id}"
2023-03-09 16:38:58 +00:00
)
if user_id and user_id > 0:
await self.data.card.update_card_last_login(req.access_code)
if req.access_code.startswith("010") or req.access_code.startswith("3"):
await self.data.card.set_chip_id_by_access_code(req.access_code, req.serial_number)
self.logger.info(f"Attempt to set chip id to {req.serial_number} for access code {req.access_code}")
return ret
2024-01-09 08:07:04 +00:00
async def handle_lookup_ex(self, data: bytes, resp_code: int) -> ADBBaseResponse:
req = ADBLookupRequest(data)
2024-01-09 19:42:17 +00:00
user_id = await self.data.card.get_user_id_from_card(req.access_code)
2024-01-09 19:42:17 +00:00
is_banned = await self.data.card.get_card_banned(req.access_code)
is_locked = await self.data.card.get_card_locked(req.access_code)
2023-08-19 05:35:37 +00:00
ret = ADBLookupExResponse.from_req(req.head, user_id)
if is_banned and is_locked:
ret.head.status = ADBStatus.BAN_SYS_USER
elif is_banned:
ret.head.status = ADBStatus.BAN_SYS
elif is_locked:
ret.head.status = ADBStatus.LOCK_USER
2023-03-09 16:38:58 +00:00
self.logger.info(
f"access_code {req.access_code} -> user_id {ret.user_id}"
2023-03-09 16:38:58 +00:00
)
2023-11-29 23:01:19 +00:00
2023-11-30 23:10:22 +00:00
if user_id and user_id > 0 and self.config.aimedb.id_secret:
2023-11-30 23:22:01 +00:00
auth_key = create_sega_auth_key(user_id, req.head.game_id, req.head.store_id, req.head.keychip_id, self.config.aimedb.id_secret, self.config.aimedb.id_lifetime_seconds)
2023-11-29 23:01:19 +00:00
if auth_key is not None:
auth_key_extra_len = 256 - len(auth_key)
2023-11-30 07:07:24 +00:00
auth_key_full = auth_key.encode() + (b"\0" * auth_key_extra_len)
2023-11-29 23:01:19 +00:00
self.logger.debug(f"Generated auth token {auth_key}")
2023-11-30 07:07:24 +00:00
ret.auth_key = auth_key_full
2023-11-29 23:01:19 +00:00
if user_id and user_id > 0:
await self.data.card.update_card_last_login(req.access_code)
return ret
2024-01-09 08:07:04 +00:00
async def handle_felica_lookup(self, data: bytes, resp_code: int) -> bytes:
"""
On official, the IDm is used as a key to look up the stored access code in a large
database. We do not have access to that database so we have to make due with what we got.
Interestingly, namco games are able to read S_PAD0 and send the server the correct access
code, but aimedb doesn't. Until somebody either enters the correct code manually, or scans
on a game that reads it correctly from the card, this will have to do. It's the same conversion
used on the big boy networks.
"""
req = ADBFelicaLookupRequest(data)
card = await self.data.card.get_card_by_idm(req.idm)
if not card:
ac = self.data.card.to_access_code(req.idm)
test = await self.data.card.get_card_by_access_code(ac)
if test:
await self.data.card.set_idm_by_access_code(ac, req.idm)
else:
ac = card['access_code']
self.logger.info(
f"idm {req.idm} ipm {req.pmm} -> access_code {ac}"
2023-03-09 16:38:58 +00:00
)
2023-08-19 05:35:37 +00:00
return ADBFelicaLookupResponse.from_req(req.head, ac)
2024-01-09 08:07:04 +00:00
async def handle_felica_register(self, data: bytes, resp_code: int) -> bytes:
"""
Used to register felica moble access codes. Will never be used on our network
because we don't implement felica_lookup properly.
"""
req = ADBFelicaLookupRequest(data)
2024-01-10 00:10:39 +00:00
ac = self.data.card.to_access_code(req.idm)
if self.config.server.allow_user_registration:
2024-01-09 19:42:17 +00:00
user_id = await self.data.user.create_user()
if user_id is None:
self.logger.error("Failed to register user!")
user_id = -1
else:
2024-01-09 19:42:17 +00:00
card_id = await self.data.card.create_card(user_id, ac)
if card_id is None:
self.logger.error("Failed to register card!")
user_id = -1
self.logger.info(
f"Register access code {ac} (IDm: {req.idm} PMm: {req.pmm}) -> user_id {user_id}"
)
2023-03-09 16:38:58 +00:00
else:
self.logger.info(
f"Registration blocked!: access code {ac} (IDm: {req.idm} PMm: {req.pmm})"
)
if user_id > 0:
await self.data.card.update_card_last_login(ac)
2023-08-19 05:35:37 +00:00
return ADBFelicaLookupResponse.from_req(req.head, ac)
2024-01-09 08:07:04 +00:00
async def handle_felica_lookup_ex(self, data: bytes, resp_code: int) -> bytes:
req = ADBFelicaLookup2Request(data)
user_id = None
card = await self.data.card.get_card_by_idm(req.idm)
if not card:
access_code = self.data.card.to_access_code(req.idm)
card = await self.data.card.get_card_by_access_code(access_code)
if card:
user_id = card['user']
await self.data.card.set_idm_by_access_code(access_code, req.idm)
else:
user_id = card['user']
access_code = card['access_code']
2023-03-09 16:38:58 +00:00
if user_id is None:
user_id = -1
2023-03-09 16:38:58 +00:00
self.logger.info(
f"idm {req.idm} ipm {req.pmm} -> access_code {access_code} user_id {user_id}"
2023-03-09 16:38:58 +00:00
)
2023-11-29 23:01:19 +00:00
resp = ADBFelicaLookup2Response.from_req(req.head, user_id, access_code)
if user_id > 0:
if card['is_banned'] and card['is_locked']:
resp.head.status = ADBStatus.BAN_SYS_USER
elif card['is_banned']:
resp.head.status = ADBStatus.BAN_SYS
elif card['is_locked']:
resp.head.status = ADBStatus.LOCK_USER
2023-11-29 23:01:19 +00:00
2023-11-30 23:10:22 +00:00
if user_id and user_id > 0 and self.config.aimedb.id_secret:
2023-11-30 23:22:01 +00:00
auth_key = create_sega_auth_key(user_id, req.head.game_id, req.head.store_id, req.head.keychip_id, self.config.aimedb.id_secret, self.config.aimedb.id_lifetime_seconds)
2023-11-29 23:01:19 +00:00
if auth_key is not None:
auth_key_extra_len = 256 - len(auth_key)
2023-11-30 07:07:24 +00:00
auth_key_full = auth_key.encode() + (b"\0" * auth_key_extra_len)
2023-11-29 23:01:19 +00:00
self.logger.debug(f"Generated auth token {auth_key}")
2023-11-30 07:07:24 +00:00
resp.auth_key = auth_key_full
if user_id and user_id > 0:
await self.data.card.update_card_last_login(access_code)
2023-11-29 23:01:19 +00:00
return resp
2023-03-09 16:38:58 +00:00
2024-01-09 08:07:04 +00:00
async def handle_campaign_clear(self, data: bytes, resp_code: int) -> ADBBaseResponse:
req = ADBCampaignClearRequest(data)
2023-03-09 16:38:58 +00:00
2023-08-19 05:35:37 +00:00
resp = ADBCampaignClearResponse.from_req(req.head)
# We don't support campaign stuff
return resp
2024-01-09 08:07:04 +00:00
async def handle_register(self, data: bytes, resp_code: int) -> bytes:
req = ADBLookupRequest(data)
user_id = -1
2023-02-19 05:07:14 +00:00
if self.config.server.allow_user_registration:
2024-01-09 19:42:17 +00:00
user_id = await self.data.user.create_user()
2023-03-09 16:38:58 +00:00
if user_id is None:
self.logger.error("Failed to register user!")
user_id = -1
else:
2024-01-09 19:42:17 +00:00
card_id = await self.data.card.create_card(user_id, req.access_code)
2023-03-09 16:38:58 +00:00
if card_id is None:
self.logger.error("Failed to register card!")
user_id = -1
2023-03-09 16:38:58 +00:00
self.logger.info(
f"Register access code {req.access_code} -> user_id {user_id}"
2023-03-09 16:38:58 +00:00
)
else:
2023-03-09 16:38:58 +00:00
self.logger.info(
f"Registration blocked!: access code {req.access_code}"
2023-03-09 16:38:58 +00:00
)
if user_id > 0:
if req.access_code.startswith("010") or req.access_code.startswith("3"):
await self.data.card.set_chip_id_by_access_code(req.access_code, req.serial_number)
self.logger.info(f"Attempt to set chip id to {req.serial_number} for access code {req.access_code}")
elif req.access_code.startswith("0008"):
idm = self.data.card.to_idm(req.access_code)
await self.data.card.set_idm_by_access_code(req.access_code, idm)
self.logger.info(f"Attempt to set IDm to {idm} for access code {req.access_code}")
2023-08-19 05:35:37 +00:00
resp = ADBLookupResponse.from_req(req.head, user_id)
if resp.user_id <= 0:
resp.head.status = ADBStatus.BAN_SYS # Closest we can get to a "You cannot register"
else:
await self.data.card.update_card_last_login(req.access_code)
return resp
# TODO: Save these in some capacity, as deemed relevant
2024-01-09 08:07:04 +00:00
async def handle_status_log(self, data: bytes, resp_code: int) -> bytes:
req = ADBStatusLogRequest(data)
self.logger.info(f"User {req.aime_id} logged {req.status.name} event")
2023-08-19 05:35:37 +00:00
return ADBBaseResponse(resp_code, 0x20, 1, req.head.game_id, req.head.store_id, req.head.keychip_id, req.head.protocol_ver)
2024-01-09 08:07:04 +00:00
async def handle_log(self, data: bytes, resp_code: int) -> bytes:
req = ADBLogRequest(data)
self.logger.info(f"User {req.aime_id} logged {req.status.name} event, credit_ct: {req.credit_ct} bet_ct: {req.bet_ct} won_ct: {req.won_ct}")
2023-08-19 05:35:37 +00:00
return ADBBaseResponse(resp_code, 0x20, 1, req.head.game_id, req.head.store_id, req.head.keychip_id, req.head.protocol_ver)
2024-01-09 08:07:04 +00:00
async def handle_log_ex(self, data: bytes, resp_code: int) -> bytes:
req = ADBLogExRequest(data)
2023-08-20 23:55:26 +00:00
strs = []
self.logger.info(f"Recieved {req.num_logs} or {len(req.logs)} logs")
for x in range(req.num_logs):
self.logger.debug(f"User {req.logs[x].aime_id} logged {req.logs[x].status.name} event, credit_ct: {req.logs[x].credit_ct} bet_ct: {req.logs[x].bet_ct} won_ct: {req.logs[x].won_ct}")
2023-08-20 23:56:16 +00:00
return ADBLogExResponse.from_req(req.head)