From 2727afe386fe60cb61fe6112c7a73455626ad057 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Lukas=20Br=C3=BCbach?= Date: Thu, 28 May 2026 08:58:16 +0200 Subject: [PATCH] Log. Took 1 hour 10 minutes --- .../remote/game/server_abstract_player.cpp | 179 +++++++++++++++++- .../server/remote/game/server_game.cpp | 95 +++++++++- 2 files changed, 267 insertions(+), 7 deletions(-) diff --git a/libcockatrice_network/libcockatrice/network/server/remote/game/server_abstract_player.cpp b/libcockatrice_network/libcockatrice/network/server/remote/game/server_abstract_player.cpp index 3e489233c..ab2708943 100644 --- a/libcockatrice_network/libcockatrice/network/server/remote/game/server_abstract_player.cpp +++ b/libcockatrice_network/libcockatrice/network/server/remote/game/server_abstract_player.cpp @@ -7,6 +7,7 @@ #include "server_move_card_struct.h" #include +#include #include #include #include @@ -52,6 +53,8 @@ #include #include +Q_LOGGING_CATEGORY(arrowLog, "cockatrice.server.arrows") + Server_AbstractPlayer::Server_AbstractPlayer(Server_Game *_game, int _playerId, const ServerInfo_User &_userInfo, @@ -84,11 +87,23 @@ int Server_AbstractPlayer::newCardId() int Server_AbstractPlayer::newArrowId() const { int id = 0; + + qCDebug(arrowLog) << "[ArrowId] Calculating next arrow id for player" << playerId + << "- existing arrow count:" << arrows.size(); + for (Server_Arrow *a : arrows) { + qCDebug(arrowLog) << "[ArrowId] Existing arrow:" + << "id=" << a->getId() + << "startCard=" << (a->getStartCard() ? a->getStartCard()->getId() : -1) + << "target=" << a->getTargetItem(); + if (a->getId() > id) { id = a->getId(); } } + + qCDebug(arrowLog) << "[ArrowId] Next arrow id for player" << playerId << "will be" << (id + 1); + return id + 1; } @@ -117,23 +132,68 @@ void Server_AbstractPlayer::addZone(Server_CardZone *zone) void Server_AbstractPlayer::addArrow(Server_Arrow *arrow) { + qCDebug(arrowLog) << "[ArrowAdd]" + << "player=" << playerId << "arrowId=" << arrow->getId() + << "startCard=" << (arrow->getStartCard() ? arrow->getStartCard()->getId() : -1) + << "targetItem=" << arrow->getTargetItem() << "existingArrowCount=" << arrows.size(); + arrows.insert(arrow->getId(), arrow); + + qCDebug(arrowLog) << "[ArrowAdd] Complete:" + << "newArrowCount=" << arrows.size(); } void Server_AbstractPlayer::updateArrowId(int id) { + qCDebug(arrowLog) << "[ArrowUpdateId]" + << "player=" << playerId << "oldId=" << id; + auto *arrow = arrows.take(id); + + if (!arrow) { + qCWarning(arrowLog) << "[ArrowUpdateId] FAILED:" + << "could not find arrow with id" << id; + return; + } + + qCDebug(arrowLog) << "[ArrowUpdateId]" + << "newId=" << arrow->getId(); + arrows.insert(arrow->getId(), arrow); + + qCDebug(arrowLog) << "[ArrowUpdateId] Complete"; } bool Server_AbstractPlayer::deleteArrow(int arrowId) { - Server_Arrow *arrow = arrows.value(arrowId, 0); + qCDebug(arrowLog) << "[ArrowDelete]" + << "player=" << playerId << "requestedArrowId=" << arrowId; + + Server_Arrow *arrow = arrows.value(arrowId, nullptr); + if (!arrow) { + qCWarning(arrowLog) << "[ArrowDelete] FAILED:" + << "arrow not found" + << "arrowId=" << arrowId; + return false; } + + qCDebug(arrowLog) << "[ArrowDelete]" + << "startCard=" << (arrow->getStartCard() ? arrow->getStartCard()->getId() : -1) + << "targetItem=" << arrow->getTargetItem(); + arrows.remove(arrowId); + + qCDebug(arrowLog) << "[ArrowDelete]" + << "removedFromMap" + << "remainingArrowCount=" << arrows.size(); + delete arrow; + + qCDebug(arrowLog) << "[ArrowDelete] Complete:" + << "deletedArrowId=" << arrowId; + return true; } @@ -388,15 +448,24 @@ void Server_AbstractPlayer::processMoveCard(GameEventStorage &ges, } if (startzone != targetzone) { + qCDebug(arrowLog) << "[ArrowCleanupOnMove]" + << "movingCard=" << card->getId() << "fromZone=" << startzone->getName() + << "toZone=" << targetzone->getName(); // Delete all arrows from and to the card for (auto *player : game->getPlayers().values()) { QList arrowsToDelete; for (Server_Arrow *arrow : player->getArrows()) { if ((arrow->getStartCard() == card) || (arrow->getTargetItem() == card)) { + qCDebug(arrowLog) << "[ArrowCleanupOnMove]" + << "player=" << player->getPlayerId() + << "schedulingArrowDelete=" << arrow->getId() << "because card" << card->getId() + << "is involved"; arrowsToDelete.append(arrow->getId()); } } for (int j : arrowsToDelete) { + qCDebug(arrowLog) << "[ArrowCleanupOnMove]" + << "deletingArrowId=" << j; Event_DeleteArrow event; event.set_arrow_id(j); ges.enqueueGameEvent(event, player->getPlayerId()); @@ -1120,50 +1189,117 @@ Server_AbstractPlayer::cmdCreateToken(const Command_CreateToken &cmd, ResponseCo // Copy Arrows for (auto *player : game->getPlayers().values()) { QList changedArrowIds; + for (Server_Arrow *arrow : player->getArrows()) { + + qCDebug(arrowLog) << "[ArrowTransformMigration] Inspecting arrow" + << "player=" << player->getPlayerId() << "arrowId=" << arrow->getId(); + bool sendGameEvent = false; + const auto *startCard = arrow->getStartCard(); + if (startCard == targetCard) { + + qCDebug(arrowLog) << "[ArrowTransformMigration] Replacing start card" + << "arrowId=" << arrow->getId() << "oldStartCard=" << targetCard->getId() + << "newStartCard=" << card->getId(); + sendGameEvent = true; + arrow->setStartCard(card); startCard = card; } + const auto *targetItem = arrow->getTargetItem(); + if (targetItem == targetCard) { + + qCDebug(arrowLog) << "[ArrowTransformMigration] Replacing target item" + << "arrowId=" << arrow->getId() << "oldTargetCard=" << targetCard->getId() + << "newTargetCard=" << card->getId(); + sendGameEvent = true; + arrow->setTargetItem(card); targetItem = card; } + if (sendGameEvent) { + const int oldId = arrow->getId(); + + qCDebug(arrowLog) << "[ArrowTransformMigration] Migrating arrow" + << "player=" << player->getPlayerId() << "oldArrowId=" << oldId; + changedArrowIds.append(oldId); Event_DeleteArrow deleteEvent; deleteEvent.set_arrow_id(oldId); + + qCDebug(arrowLog) << "[ArrowTransformMigration] Enqueue delete event" + << "arrowId=" << oldId; + ges.enqueueGameEvent(deleteEvent, player->getPlayerId()); Event_CreateArrow createEvent; ServerInfo_Arrow *arrowInfo = createEvent.mutable_arrow_info(); + const int newId = player->newArrowId(); + + qCDebug(arrowLog) << "[ArrowTransformMigration] Assigning new arrow id" + << "oldId=" << oldId << "newId=" << newId; + arrow->setId(newId); + arrowInfo->set_id(newId); arrowInfo->set_start_player_id(player->getPlayerId()); arrowInfo->set_start_zone(startCard->getZone()->getName().toStdString()); arrowInfo->set_start_card_id(startCard->getId()); + const auto *arrowTargetPlayer = qobject_cast(targetItem); + if (arrowTargetPlayer != nullptr) { + + qCDebug(arrowLog) << "[ArrowTransformMigration] Target is player" + << "targetPlayer=" << arrowTargetPlayer->getPlayerId(); + arrowInfo->set_target_player_id(arrowTargetPlayer->getPlayerId()); + } else { + const auto *arrowTargetCard = qobject_cast(targetItem); + + qCDebug(arrowLog) + << "[ArrowTransformMigration] Target is card" + << "targetPlayer=" << arrowTargetCard->getZone()->getPlayer()->getPlayerId() + << "targetZone=" << arrowTargetCard->getZone()->getName() + << "targetCard=" << arrowTargetCard->getId(); + arrowInfo->set_target_player_id(arrowTargetCard->getZone()->getPlayer()->getPlayerId()); + arrowInfo->set_target_zone(arrowTargetCard->getZone()->getName().toStdString()); + arrowInfo->set_target_card_id(arrowTargetCard->getId()); } + arrowInfo->mutable_arrow_color()->CopyFrom(arrow->getColor()); + + qCDebug(arrowLog) << "[ArrowTransformMigration] Enqueue create event" + << "newArrowId=" << newId; + ges.enqueueGameEvent(createEvent, player->getPlayerId()); + + qCDebug(arrowLog) << "[ArrowTransformMigration] Migration complete" + << "oldArrowId=" << oldId << "newArrowId=" << newId; } } + for (int id : changedArrowIds) { + + qCDebug(arrowLog) << "[ArrowTransformMigration] Updating arrow map" + << "oldId=" << id; + player->updateArrowId(id); } } @@ -1261,6 +1397,11 @@ Server_AbstractPlayer::cmdCreateArrow(const Command_CreateArrow &cmd, ResponseCo for (Server_Arrow *temp : arrows) { if ((temp->getStartCard() == startCard) && (temp->getTargetItem() == targetItem)) { + + qCWarning(arrowLog) << "[ArrowCreate] Duplicate rejected:" + << "player=" << playerId << "existingArrowId=" << temp->getId() + << "startCard=" << startCard->getId() << "targetItem=" << targetItem; + return Response::RespContextError; } } @@ -1270,6 +1411,10 @@ Server_AbstractPlayer::cmdCreateArrow(const Command_CreateArrow &cmd, ResponseCo auto arrow = new Server_Arrow(newArrowId(), startCard, targetItem, cmd.arrow_color(), currentPhase, deletionPhase); addArrow(arrow); + qCDebug(arrowLog) << "[ArrowCreate]" + << "requestingPlayer=" << playerId << "startPlayer=" << startPlayer->getPlayerId() + << "targetPlayer=" << targetPlayer->getPlayerId() << "startZone=" << startZoneName + << "startCard=" << startCard->getId() << "targetIsPlayer=" << playerTarget; Event_CreateArrow event; ServerInfo_Arrow *arrowInfo = event.mutable_arrow_info(); arrowInfo->set_id(arrow->getId()); @@ -1290,21 +1435,53 @@ Server_AbstractPlayer::cmdCreateArrow(const Command_CreateArrow &cmd, ResponseCo Response::ResponseCode Server_AbstractPlayer::cmdDeleteArrow(const Command_DeleteArrow &cmd, ResponseContainer & /*rc*/, GameEventStorage &ges) { + qCDebug(arrowLog) << "[ArrowDeleteCommand] Request received" + << "requestingPlayer=" << playerId << "arrowId=" << cmd.arrow_id(); + if (!game->getGameStarted()) { + + qCWarning(arrowLog) << "[ArrowDeleteCommand] Rejected:" + << "game not started" + << "player=" << playerId << "arrowId=" << cmd.arrow_id(); + return Response::RespGameNotStarted; } + if (conceded) { + + qCWarning(arrowLog) << "[ArrowDeleteCommand] Rejected:" + << "player already conceded" + << "player=" << playerId << "arrowId=" << cmd.arrow_id(); + return Response::RespContextError; } + qCDebug(arrowLog) << "[ArrowDeleteCommand] Attempting delete" + << "player=" << playerId << "arrowId=" << cmd.arrow_id(); + if (!deleteArrow(cmd.arrow_id())) { + + qCWarning(arrowLog) << "[ArrowDeleteCommand] Delete failed:" + << "arrow not found" + << "player=" << playerId << "arrowId=" << cmd.arrow_id(); + return Response::RespNameNotFound; } + qCDebug(arrowLog) << "[ArrowDeleteCommand] Delete successful" + << "player=" << playerId << "arrowId=" << cmd.arrow_id(); + Event_DeleteArrow event; event.set_arrow_id(cmd.arrow_id()); + + qCDebug(arrowLog) << "[ArrowDeleteCommand] Enqueueing delete event" + << "player=" << playerId << "arrowId=" << cmd.arrow_id(); + ges.enqueueGameEvent(event, playerId); + qCDebug(arrowLog) << "[ArrowDeleteCommand] Complete" + << "player=" << playerId << "arrowId=" << cmd.arrow_id(); + return Response::RespOk; } diff --git a/libcockatrice_network/libcockatrice/network/server/remote/game/server_game.cpp b/libcockatrice_network/libcockatrice/network/server/remote/game/server_game.cpp index 50fff4812..67a76d18a 100644 --- a/libcockatrice_network/libcockatrice/network/server/remote/game/server_game.cpp +++ b/libcockatrice_network/libcockatrice/network/server/remote/game/server_game.cpp @@ -32,6 +32,7 @@ #include "server_spectator.h" #include +#include #include #include #include @@ -53,6 +54,8 @@ #include #include +Q_LOGGING_CATEGORY(arrowServerLog, "cockatrice.server.game_arrows") + Server_Game::Server_Game(const ServerInfo_User &_creatorInfo, int _gameId, const QString &_description, @@ -599,35 +602,85 @@ void Server_Game::removeArrowsRelatedToPlayer(GameEventStorage &ges, Server_Abst { QMutexLocker locker(&gameMutex); - // Remove all arrows of other players pointing to the player being removed or to one of his cards. - // Also remove all arrows starting at one of his cards. This is necessary since players can create - // arrows that start at another person's cards. + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] START" + << "targetPlayer=" << player->getPlayerId(); + for (Server_AbstractPlayer *anyPlayer : getPlayers().values()) { + QList toDelete; + + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] Scanning player" + << "player=" << anyPlayer->getPlayerId() + << "arrowCount=" << anyPlayer->getArrows().size(); + for (auto *arrow : anyPlayer->getArrows().values()) { + + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] Inspect arrow" + << "arrowId=" << arrow->getId() << "ownerPlayer=" << anyPlayer->getPlayerId(); + auto *targetCard = qobject_cast(arrow->getTargetItem()); + + bool marked = false; + if (targetCard) { + if (targetCard->getZone() != nullptr && targetCard->getZone()->getPlayer() == player) { + + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] MATCH targetCard belongs to player" + << "arrowId=" << arrow->getId() << "targetCard=" << targetCard->getId(); + toDelete.append(arrow); + marked = true; } + } else if (arrow->getTargetItem() == player) { + + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] MATCH target is player" + << "arrowId=" << arrow->getId(); + toDelete.append(arrow); + marked = true; } - // Don't use else here! It has to happen regardless of whether targetCard == 0. + // IMPORTANT: always evaluated if (arrow->getStartCard()->getZone() != nullptr && arrow->getStartCard()->getZone()->getPlayer() == player) { + + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] MATCH startCard belongs to player" + << "arrowId=" << arrow->getId() + << "startCard=" << arrow->getStartCard()->getId(); + toDelete.append(arrow); + marked = true; + } + + if (!marked) { + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] KEEP" + << "arrowId=" << arrow->getId(); } } + + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] Deletion batch ready" + << "player=" << anyPlayer->getPlayerId() << "count=" << toDelete.size(); + for (auto *arrow : toDelete) { + + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] DELETING" + << "arrowId=" << arrow->getId() << "fromPlayer=" << anyPlayer->getPlayerId(); + Event_DeleteArrow event; event.set_arrow_id(arrow->getId()); + ges.enqueueGameEvent(event, anyPlayer->getPlayerId()); anyPlayer->deleteArrow(arrow->getId()); + + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] Deleted" + << "arrowId=" << arrow->getId(); } } + + qCDebug(arrowServerLog) << "[ArrowPlayerCleanup] END"; } void Server_Game::unattachCards(GameEventStorage &ges, Server_AbstractPlayer *player) @@ -701,17 +754,47 @@ void Server_Game::removeArrows(int newPhase, bool force) { QMutexLocker locker(&gameMutex); + qCDebug(arrowServerLog) << "[ArrowPhaseCleanup] START" + << "newPhase=" << newPhase << "force=" << force << "playerCount=" << getPlayers().size(); + for (auto *anyPlayer : getPlayers().values()) { - for (auto *arrowToDelete : anyPlayer->getArrows().values()) { // values creates a copy - if (force || arrowToDelete->checkPhaseDeletion(newPhase)) { + + qCDebug(arrowServerLog) << "[ArrowPhaseCleanup] Player scan" + << "player=" << anyPlayer->getPlayerId() + << "arrowCount=" << anyPlayer->getArrows().size(); + + for (auto *arrowToDelete : anyPlayer->getArrows().values()) { + + qCDebug(arrowServerLog) << "[ArrowPhaseCleanup] Inspect arrow" + << "player=" << anyPlayer->getPlayerId() << "arrowId=" << arrowToDelete->getId() + << "startCard=" + << (arrowToDelete->getStartCard() ? arrowToDelete->getStartCard()->getId() : -1) + << "targetItem=" << arrowToDelete->getTargetItem() + << "currentPhaseOk=" << arrowToDelete->checkPhaseDeletion(newPhase); + + const bool shouldDelete = (force || arrowToDelete->checkPhaseDeletion(newPhase)); + + if (shouldDelete) { + + qCDebug(arrowServerLog) << "[ArrowPhaseCleanup] DELETING" + << "player=" << anyPlayer->getPlayerId() << "arrowId=" << arrowToDelete->getId() + << "reason=" << (force ? "FORCE" : "PHASE"); + Event_DeleteArrow event; event.set_arrow_id(arrowToDelete->getId()); + sendGameEventContainer(prepareGameEvent(event, anyPlayer->getPlayerId())); anyPlayer->deleteArrow(arrowToDelete->getId()); + + qCDebug(arrowServerLog) << "[ArrowPhaseCleanup] Deleted" + << "player=" << anyPlayer->getPlayerId() + << "arrowId=" << arrowToDelete->getId(); } } } + + qCDebug(arrowServerLog) << "[ArrowPhaseCleanup] END"; } void Server_Game::nextTurn()