add: significantly improved the dedicated server logging system

- add ServerLogManager to Minecraft.Server as the single entry point for dedicated-server log output
- forward CMinecraftApp logger output to the server logger when running with g_Win64DedicatedServer
- add named network logs for incoming, accepted, rejected, and disconnected connections
- cache connection metadata by smallId so player name and remote IP remain available for disconnect logs
- keep Minecraft.Client changes minimal by using lightweight hook points and handling log orchestration on the server side
This commit is contained in:
kuwacom 2026-03-08 15:22:00 +09:00
parent b250be7387
commit 71fd1e3a62
12 changed files with 731 additions and 69 deletions

View file

@ -106,6 +106,7 @@ list(APPEND MINECRAFT_SERVER_SOURCES
"${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/Common/FileUtils.cpp" "${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/Common/FileUtils.cpp"
"${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/Common/StringUtils.cpp" "${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/Common/StringUtils.cpp"
"${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/ServerLogger.cpp" "${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/ServerLogger.cpp"
"${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/ServerLogManager.cpp"
"${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/ServerProperties.cpp" "${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/ServerProperties.cpp"
"${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/vendor/linenoise/linenoise.c" "${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/vendor/linenoise/linenoise.c"
"${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/WorldManager.cpp" "${CMAKE_CURRENT_SOURCE_DIR}/Minecraft.Server/WorldManager.cpp"

View file

@ -1,21 +1,32 @@
#include "stdafx.h" #include "stdafx.h"
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
#include "..\..\Minecraft.Server\ServerLogManager.h"
#endif
//-------------------------------------------------------------------------------------- //--------------------------------------------------------------------------------------
// Name: DebugSpewV() // Name: DebugSpewV()
// Desc: Internal helper function // Desc: Internal helper function
//-------------------------------------------------------------------------------------- //--------------------------------------------------------------------------------------
#ifndef _CONTENT_PACKAGE #ifndef _CONTENT_PACKAGE
static VOID DebugSpewV( const CHAR* strFormat, const va_list pArgList ) static VOID DebugSpewV( const CHAR* strFormat, va_list pArgList )
{ {
#if defined __PS3__ || defined __ORBIS__ || defined __PSVITA__ #if defined __PS3__ || defined __ORBIS__ || defined __PSVITA__
assert(0); assert(0);
#else #else
CHAR str[2048]; #if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
// Use the secure CRT to avoid buffer overruns. Specify a count of // Dedicated server routes legacy debug spew through ServerLogger to preserve CLI prompt handling.
// _TRUNCATE so that too long strings will be silently truncated if (ServerRuntime::ServerLogManager::ShouldForwardClientDebugLogs())
// rather than triggering an error. {
_vsnprintf_s( str, _TRUNCATE, strFormat, pArgList ); ServerRuntime::ServerLogManager::ForwardClientDebugSpewLogV(strFormat, pArgList);
OutputDebugStringA( str ); return;
}
#endif
CHAR str[2048];
// Use the secure CRT to avoid buffer overruns. Specify a count of
// _TRUNCATE so that too long strings will be silently truncated
// rather than triggering an error.
_vsnprintf_s( str, _TRUNCATE, strFormat, pArgList );
OutputDebugStringA( str );
#endif #endif
} }
#endif #endif
@ -31,10 +42,9 @@ VOID CDECL DebugPrintf( const CHAR* strFormat, ... )
#endif #endif
{ {
#ifndef _CONTENT_PACKAGE #ifndef _CONTENT_PACKAGE
va_list pArgList; va_list pArgList;
va_start( pArgList, strFormat ); va_start( pArgList, strFormat );
DebugSpewV( strFormat, pArgList ); DebugSpewV( strFormat, pArgList );
va_end( pArgList ); va_end( pArgList );
#endif #endif
} }

View file

@ -38,6 +38,9 @@
#include "GameRules\ConsoleSchematicFile.h" #include "GameRules\ConsoleSchematicFile.h"
#include "..\User.h" #include "..\User.h"
#include "..\..\Minecraft.World\LevelData.h" #include "..\..\Minecraft.World\LevelData.h"
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
#include "..\..\Minecraft.Server\ServerLogManager.h"
#endif
#include "..\..\Minecraft.World\net.minecraft.world.entity.player.h" #include "..\..\Minecraft.World\net.minecraft.world.entity.player.h"
#include "..\EntityRenderDispatcher.h" #include "..\EntityRenderDispatcher.h"
#include "..\..\Minecraft.World\compression.h" #include "..\..\Minecraft.World\compression.h"
@ -240,12 +243,21 @@ void CMinecraftApp::DebugPrintf(const char *szFormat, ...)
{ {
#ifndef _FINAL_BUILD #ifndef _FINAL_BUILD
char buf[1024]; va_list ap;
va_list ap; va_start(ap, szFormat);
va_start(ap, szFormat); #if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
vsnprintf(buf, sizeof(buf), szFormat, ap); // Dedicated server routes client debug spew through ServerLogger so CLI output stays prompt-safe.
va_end(ap); if (ServerRuntime::ServerLogManager::ShouldForwardClientDebugLogs())
OutputDebugStringA(buf); {
ServerRuntime::ServerLogManager::ForwardClientAppDebugLogV(szFormat, ap);
va_end(ap);
return;
}
#endif
char buf[1024];
vsnprintf(buf, sizeof(buf), szFormat, ap);
va_end(ap);
OutputDebugStringA(buf);
#endif #endif
} }
@ -253,53 +265,62 @@ void CMinecraftApp::DebugPrintf(const char *szFormat, ...)
void CMinecraftApp::DebugPrintf(int user, const char *szFormat, ...) void CMinecraftApp::DebugPrintf(int user, const char *szFormat, ...)
{ {
#ifndef _FINAL_BUILD #ifndef _FINAL_BUILD
if(user == USER_NONE) if(user == USER_NONE)
return; return;
char buf[1024]; va_list ap;
va_list ap; va_start(ap, szFormat);
va_start(ap, szFormat); #if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
vsnprintf(buf, sizeof(buf), szFormat, ap); // Dedicated server routes client debug spew through ServerLogger so CLI output stays prompt-safe.
va_end(ap); if (ServerRuntime::ServerLogManager::ShouldForwardClientDebugLogs())
{
ServerRuntime::ServerLogManager::ForwardClientUserDebugLogV(user, szFormat, ap);
va_end(ap);
return;
}
#endif
char buf[1024];
vsnprintf(buf, sizeof(buf), szFormat, ap);
va_end(ap);
#ifdef __PS3__ #ifdef __PS3__
unsigned int writelen; unsigned int writelen;
sys_tty_write(SYS_TTYP_USER1 + ( user - 1 ), buf, strlen(buf), &writelen ); sys_tty_write(SYS_TTYP_USER1 + ( user - 1 ), buf, strlen(buf), &writelen );
#elif defined __PSVITA__ #elif defined __PSVITA__
switch(user) switch(user)
{ {
case 0: case 0:
{ {
SceUID tty2 = sceIoOpen("tty2:", SCE_O_WRONLY, 0); SceUID tty2 = sceIoOpen("tty2:", SCE_O_WRONLY, 0);
if(tty2>=0) if(tty2>=0)
{ {
std::string string1(buf); std::string string1(buf);
sceIoWrite(tty2, string1.c_str(), string1.length()); sceIoWrite(tty2, string1.c_str(), string1.length());
sceIoClose(tty2); sceIoClose(tty2);
} }
} }
break; break;
case 1: case 1:
{ {
SceUID tty3 = sceIoOpen("tty3:", SCE_O_WRONLY, 0); SceUID tty3 = sceIoOpen("tty3:", SCE_O_WRONLY, 0);
if(tty3>=0) if(tty3>=0)
{ {
std::string string1(buf); std::string string1(buf);
sceIoWrite(tty3, string1.c_str(), string1.length()); sceIoWrite(tty3, string1.c_str(), string1.length());
sceIoClose(tty3); sceIoClose(tty3);
} }
} }
break; break;
default: default:
OutputDebugStringA(buf); OutputDebugStringA(buf);
break; break;
} }
#else #else
OutputDebugStringA(buf); OutputDebugStringA(buf);
#endif #endif
#ifndef _XBOX #ifndef _XBOX
if(user == USER_UI) if(user == USER_UI)
{ {
ui.logDebugString(buf); ui.logDebugString(buf);
} }
#endif #endif
#endif #endif
} }

View file

@ -14,6 +14,10 @@
#include "..\Minecraft.World\net.minecraft.world.item.h" #include "..\Minecraft.World\net.minecraft.world.item.h"
#include "..\Minecraft.World\SharedConstants.h" #include "..\Minecraft.World\SharedConstants.h"
#include "Settings.h" #include "Settings.h"
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
#include "..\Minecraft.Server\ServerLogManager.h"
#include "..\Minecraft.World\Socket.h"
#endif
// #ifdef __PS3__ // #ifdef __PS3__
// #include "PS3\Network\NetworkPlayerSony.h" // #include "PS3\Network\NetworkPlayerSony.h"
// #endif // #endif
@ -24,6 +28,25 @@ Random *PendingConnection::random = new Random();
bool g_bRejectDuplicateNames = true; bool g_bRejectDuplicateNames = true;
#endif #endif
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
namespace
{
static unsigned char GetPendingConnectionSmallId(Connection *connection)
{
if (connection != NULL)
{
Socket *socket = connection->getSocket();
if (socket != NULL)
{
return socket->getSmallId();
}
}
return 0;
}
}
#endif
PendingConnection::PendingConnection(MinecraftServer *server, Socket *socket, const wstring& id) PendingConnection::PendingConnection(MinecraftServer *server, Socket *socket, const wstring& id)
{ {
// 4J - added initialisers // 4J - added initialisers
@ -196,10 +219,16 @@ void PendingConnection::handleLogin(shared_ptr<LoginPacket> packet)
} }
else if (bannedXuid) else if (bannedXuid)
{ {
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
ServerRuntime::ServerLogManager::OnRejectedPlayerLogin(GetPendingConnectionSmallId(connection), name, ServerRuntime::ServerLogManager::eLoginRejectReason_BannedXuid);
#endif
disconnect(DisconnectPacket::eDisconnect_Banned); disconnect(DisconnectPacket::eDisconnect_Banned);
} }
else if (duplicateXuid) else if (duplicateXuid)
{ {
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
ServerRuntime::ServerLogManager::OnRejectedPlayerLogin(GetPendingConnectionSmallId(connection), name, ServerRuntime::ServerLogManager::eLoginRejectReason_DuplicateXuid);
#endif
// if same XUID already in use by another player so disconnect this one. // if same XUID already in use by another player so disconnect this one.
app.DebugPrintf("Rejecting duplicate xuid for name: %ls\n", name.c_str()); app.DebugPrintf("Rejecting duplicate xuid for name: %ls\n", name.c_str());
disconnect(DisconnectPacket::eDisconnect_Banned); disconnect(DisconnectPacket::eDisconnect_Banned);
@ -219,6 +248,9 @@ void PendingConnection::handleLogin(shared_ptr<LoginPacket> packet)
} }
if (nameTaken) if (nameTaken)
{ {
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
ServerRuntime::ServerLogManager::OnRejectedPlayerLogin(GetPendingConnectionSmallId(connection), name, ServerRuntime::ServerLogManager::eLoginRejectReason_DuplicateName);
#endif
app.DebugPrintf("Rejecting duplicate name: %ls\n", name.c_str()); app.DebugPrintf("Rejecting duplicate name: %ls\n", name.c_str());
disconnect(DisconnectPacket::eDisconnect_Banned); disconnect(DisconnectPacket::eDisconnect_Banned);
} }
@ -276,6 +308,9 @@ void PendingConnection::handleAcceptedLogin(shared_ptr<LoginPacket> packet)
shared_ptr<ServerPlayer> playerEntity = server->getPlayers()->getPlayerForLogin(this, name, playerXuid,packet->m_onlineXuid); shared_ptr<ServerPlayer> playerEntity = server->getPlayers()->getPlayerForLogin(this, name, playerXuid,packet->m_onlineXuid);
if (playerEntity != NULL) if (playerEntity != NULL)
{ {
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
ServerRuntime::ServerLogManager::OnAcceptedPlayerLogin(GetPendingConnectionSmallId(connection), name);
#endif
server->getPlayers()->placeNewPlayer(connection, playerEntity, packet); server->getPlayers()->placeNewPlayer(connection, playerEntity, packet);
connection = NULL; // We've moved responsibility for this over to the new PlayerConnection, NULL so we don't delete our reference to it here in our dtor connection = NULL; // We've moved responsibility for this over to the new PlayerConnection, NULL so we don't delete our reference to it here in our dtor
} }

View file

@ -34,9 +34,13 @@
// 4J Added // 4J Added
#include "..\Minecraft.World\net.minecraft.world.item.crafting.h" #include "..\Minecraft.World\net.minecraft.world.item.crafting.h"
#include "Options.h" #include "Options.h"
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
#include "..\Minecraft.Server\ServerLogManager.h"
#endif
Random PlayerConnection::random; Random PlayerConnection::random;
PlayerConnection::PlayerConnection(MinecraftServer *server, Connection *connection, shared_ptr<ServerPlayer> player) PlayerConnection::PlayerConnection(MinecraftServer *server, Connection *connection, shared_ptr<ServerPlayer> player)
{ {
// 4J - added initialisers // 4J - added initialisers
@ -66,6 +70,13 @@ PlayerConnection::PlayerConnection(MinecraftServer *server, Connection *connecti
m_offlineXUID = INVALID_XUID; m_offlineXUID = INVALID_XUID;
m_onlineXUID = INVALID_XUID; m_onlineXUID = INVALID_XUID;
m_bHasClientTickedOnce = false; m_bHasClientTickedOnce = false;
m_logSmallId = 0;
// Cache the first valid transport smallId because disconnect teardown can clear it before the server logger runs.
if (this->connection != NULL && this->connection->getSocket() != NULL)
{
m_logSmallId = this->connection->getSocket()->getSmallId();
}
setShowOnMaps(app.GetGameHostOption(eGameHostOption_Gamertags)!=0?true:false); setShowOnMaps(app.GetGameHostOption(eGameHostOption_Gamertags)!=0?true:false);
} }
@ -76,6 +87,17 @@ PlayerConnection::~PlayerConnection()
DeleteCriticalSection(&done_cs); DeleteCriticalSection(&done_cs);
} }
unsigned char PlayerConnection::getLogSmallId()
{
// Fall back to the live socket only while the cached value is still empty.
if (m_logSmallId == 0 && connection != NULL && connection->getSocket() != NULL)
{
m_logSmallId = connection->getSocket()->getSmallId();
}
return m_logSmallId;
}
void PlayerConnection::tick() void PlayerConnection::tick()
{ {
if( done ) return; if( done ) return;
@ -118,6 +140,13 @@ void PlayerConnection::disconnect(DisconnectPacket::eDisconnectReason reason)
return; return;
} }
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
ServerRuntime::ServerLogManager::OnPlayerDisconnected(
getLogSmallId(),
(player != NULL) ? player->name : std::wstring(),
reason,
true);
#endif
app.DebugPrintf("PlayerConnection disconect reason: %d\n", reason ); app.DebugPrintf("PlayerConnection disconect reason: %d\n", reason );
player->disconnect(); player->disconnect();
@ -538,7 +567,18 @@ void PlayerConnection::handleUseItem(shared_ptr<UseItemPacket> packet)
void PlayerConnection::onDisconnect(DisconnectPacket::eDisconnectReason reason, void *reasonObjects) void PlayerConnection::onDisconnect(DisconnectPacket::eDisconnectReason reason, void *reasonObjects)
{ {
EnterCriticalSection(&done_cs); EnterCriticalSection(&done_cs);
if( done ) return; if( done )
{
LeaveCriticalSection(&done_cs);
return;
}
#if defined(_WINDOWS64) && defined(MINECRAFT_SERVER_BUILD)
ServerRuntime::ServerLogManager::OnPlayerDisconnected(
getLogSmallId(),
(player != NULL) ? player->name : std::wstring(),
reason,
false);
#endif
// logger.info(player.name + " lost connection: " + reason); // logger.info(player.name + " lost connection: " + reason);
// 4J-PB - removed, since it needs to be localised in the language the client is in // 4J-PB - removed, since it needs to be localised in the language the client is in
//server->players->broadcastAll( shared_ptr<ChatPacket>( new ChatPacket(L"<22>e" + player->name + L" left the game.") ) ); //server->players->broadcastAll( shared_ptr<ChatPacket>( new ChatPacket(L"<22>e" + player->name + L" left the game.") ) );

View file

@ -37,6 +37,7 @@ private:
int dropSpamTickCount; int dropSpamTickCount;
bool m_bHasClientTickedOnce; bool m_bHasClientTickedOnce;
unsigned char m_logSmallId;
public: public:
PlayerConnection(MinecraftServer *server, Connection *connection, shared_ptr<ServerPlayer> player); PlayerConnection(MinecraftServer *server, Connection *connection, shared_ptr<ServerPlayer> player);
@ -45,6 +46,10 @@ public:
void disconnect(DisconnectPacket::eDisconnectReason reason); void disconnect(DisconnectPacket::eDisconnectReason reason);
private: private:
/**
* Returns the stable network smallId used by dedicated-server logging and refreshes it from the live socket when possible
*/
unsigned char getLogSmallId();
double xLastOk, yLastOk, zLastOk; double xLastOk, yLastOk, zLastOk;
bool synched; bool synched;

View file

@ -11,11 +11,14 @@
#if defined(MINECRAFT_SERVER_BUILD) #if defined(MINECRAFT_SERVER_BUILD)
#include "..\..\..\Minecraft.Server\Access\Access.h" #include "..\..\..\Minecraft.Server\Access\Access.h"
#include "..\..\..\Minecraft.Server\ServerLogManager.h"
#endif #endif
#include "..\..\..\Minecraft.World\DisconnectPacket.h" #include "..\..\..\Minecraft.World\DisconnectPacket.h"
#include "..\..\Minecraft.h" #include "..\..\Minecraft.h"
#include "..\4JLibs\inc\4J_Profile.h" #include "..\4JLibs\inc\4J_Profile.h"
#include <string>
static bool RecvExact(SOCKET sock, BYTE* buf, int len); static bool RecvExact(SOCKET sock, BYTE* buf, int len);
#if defined(MINECRAFT_SERVER_BUILD) #if defined(MINECRAFT_SERVER_BUILD)
@ -457,6 +460,7 @@ void WinsockNetLayer::ClearSocketForSmallId(BYTE smallId)
LeaveCriticalSection(&s_smallIdToSocketLock); LeaveCriticalSection(&s_smallIdToSocketLock);
} }
// Send reject handshake: sentinel 0xFF + DisconnectPacket wire format (1 byte id 255 + 4 byte big-endian reason). Then caller closes socket. // Send reject handshake: sentinel 0xFF + DisconnectPacket wire format (1 byte id 255 + 4 byte big-endian reason). Then caller closes socket.
static void SendRejectWithReason(SOCKET clientSocket, DisconnectPacket::eDisconnectReason reason) static void SendRejectWithReason(SOCKET clientSocket, DisconnectPacket::eDisconnectReason reason)
{ {
@ -544,12 +548,15 @@ DWORD WINAPI WinsockNetLayer::AcceptThreadProc(LPVOID param)
setsockopt(clientSocket, IPPROTO_TCP, TCP_NODELAY, (const char*)&noDelay, sizeof(noDelay)); setsockopt(clientSocket, IPPROTO_TCP, TCP_NODELAY, (const char*)&noDelay, sizeof(noDelay));
#if defined(MINECRAFT_SERVER_BUILD) #if defined(MINECRAFT_SERVER_BUILD)
std::string remoteIp;
const bool hasRemoteIp = TryGetNumericRemoteIp(remoteAddress, &remoteIp);
const char *remoteIpForLog = hasRemoteIp ? remoteIp.c_str() : "unknown";
if (g_Win64DedicatedServer) if (g_Win64DedicatedServer)
{ {
std::string remoteIp; ServerRuntime::ServerLogManager::OnIncomingTcpConnection(remoteIpForLog);
if (TryGetNumericRemoteIp(remoteAddress, &remoteIp) && ServerRuntime::Access::IsIpBanned(remoteIp)) if (hasRemoteIp && ServerRuntime::Access::IsIpBanned(remoteIp))
{ {
app.DebugPrintf("Win64 LAN: Rejecting banned ip %s\n", remoteIp.c_str()); ServerRuntime::ServerLogManager::OnRejectedTcpConnection(remoteIpForLog, ServerRuntime::ServerLogManager::eTcpRejectReason_BannedIp);
SendRejectWithReason(clientSocket, DisconnectPacket::eDisconnect_Banned); SendRejectWithReason(clientSocket, DisconnectPacket::eDisconnect_Banned);
closesocket(clientSocket); closesocket(clientSocket);
continue; continue;
@ -560,7 +567,16 @@ DWORD WINAPI WinsockNetLayer::AcceptThreadProc(LPVOID param)
extern QNET_STATE _iQNetStubState; extern QNET_STATE _iQNetStubState;
if (_iQNetStubState != QNET_STATE_GAME_PLAY) if (_iQNetStubState != QNET_STATE_GAME_PLAY)
{ {
app.DebugPrintf("Win64 LAN: Rejecting connection, game not ready\n"); #if defined(MINECRAFT_SERVER_BUILD)
if (g_Win64DedicatedServer)
{
ServerRuntime::ServerLogManager::OnRejectedTcpConnection(remoteIpForLog, ServerRuntime::ServerLogManager::eTcpRejectReason_GameNotReady);
}
else
#endif
{
app.DebugPrintf("Win64 LAN: Rejecting connection, game not ready\n");
}
closesocket(clientSocket); closesocket(clientSocket);
continue; continue;
} }
@ -568,7 +584,16 @@ DWORD WINAPI WinsockNetLayer::AcceptThreadProc(LPVOID param)
extern CPlatformNetworkManagerStub* g_pPlatformNetworkManager; extern CPlatformNetworkManagerStub* g_pPlatformNetworkManager;
if (g_pPlatformNetworkManager != NULL && !g_pPlatformNetworkManager->CanAcceptMoreConnections()) if (g_pPlatformNetworkManager != NULL && !g_pPlatformNetworkManager->CanAcceptMoreConnections())
{ {
app.DebugPrintf("Win64 LAN: Rejecting connection, server at max players\n"); #if defined(MINECRAFT_SERVER_BUILD)
if (g_Win64DedicatedServer)
{
ServerRuntime::ServerLogManager::OnRejectedTcpConnection(remoteIpForLog, ServerRuntime::ServerLogManager::eTcpRejectReason_ServerFull);
}
else
#endif
{
app.DebugPrintf("Win64 LAN: Rejecting connection, server at max players\n");
}
SendRejectWithReason(clientSocket, DisconnectPacket::eDisconnect_ServerFull); SendRejectWithReason(clientSocket, DisconnectPacket::eDisconnect_ServerFull);
closesocket(clientSocket); closesocket(clientSocket);
continue; continue;
@ -588,7 +613,16 @@ DWORD WINAPI WinsockNetLayer::AcceptThreadProc(LPVOID param)
else else
{ {
LeaveCriticalSection(&s_freeSmallIdLock); LeaveCriticalSection(&s_freeSmallIdLock);
app.DebugPrintf("Win64 LAN: Server full, rejecting connection\n"); #if defined(MINECRAFT_SERVER_BUILD)
if (g_Win64DedicatedServer)
{
ServerRuntime::ServerLogManager::OnRejectedTcpConnection(remoteIpForLog, ServerRuntime::ServerLogManager::eTcpRejectReason_ServerFull);
}
else
#endif
{
app.DebugPrintf("Win64 LAN: Server full, rejecting connection\n");
}
SendRejectWithReason(clientSocket, DisconnectPacket::eDisconnect_ServerFull); SendRejectWithReason(clientSocket, DisconnectPacket::eDisconnect_ServerFull);
closesocket(clientSocket); closesocket(clientSocket);
continue; continue;
@ -615,7 +649,16 @@ DWORD WINAPI WinsockNetLayer::AcceptThreadProc(LPVOID param)
int connIdx = (int)s_connections.size() - 1; int connIdx = (int)s_connections.size() - 1;
LeaveCriticalSection(&s_connectionsLock); LeaveCriticalSection(&s_connectionsLock);
app.DebugPrintf("Win64 LAN: Client connected, assigned smallId=%d\n", assignedSmallId); #if defined(MINECRAFT_SERVER_BUILD)
if (g_Win64DedicatedServer)
{
ServerRuntime::ServerLogManager::OnAcceptedTcpConnection(assignedSmallId, remoteIpForLog);
}
else
#endif
{
app.DebugPrintf("Win64 LAN: Client connected, assigned smallId=%d\n", assignedSmallId);
}
EnterCriticalSection(&s_smallIdToSocketLock); EnterCriticalSection(&s_smallIdToSocketLock);
s_smallIdToSocket[assignedSmallId] = clientSocket; s_smallIdToSocket[assignedSmallId] = clientSocket;

View file

@ -126,6 +126,7 @@
<ItemGroup> <ItemGroup>
<ClCompile Include="Access\Access.cpp" /> <ClCompile Include="Access\Access.cpp" />
<ClCompile Include="Access\BanManager.cpp" /> <ClCompile Include="Access\BanManager.cpp" />
<ClCompile Include="ServerLogManager.cpp" />
<ClCompile Include="..\Minecraft.Client\AbstractTexturePack.cpp" /> <ClCompile Include="..\Minecraft.Client\AbstractTexturePack.cpp" />
<ClCompile Include="..\Minecraft.Client\AchievementPopup.cpp" /> <ClCompile Include="..\Minecraft.Client\AchievementPopup.cpp" />
<ClCompile Include="..\Minecraft.Client\AchievementScreen.cpp" /> <ClCompile Include="..\Minecraft.Client\AchievementScreen.cpp" />
@ -692,6 +693,7 @@
<ClInclude Include="Common\FileUtils.h" /> <ClInclude Include="Common\FileUtils.h" />
<ClInclude Include="Common\StringUtils.h" /> <ClInclude Include="Common\StringUtils.h" />
<ClInclude Include="ServerLogger.h" /> <ClInclude Include="ServerLogger.h" />
<ClInclude Include="ServerLogManager.h" />
<ClInclude Include="ServerProperties.h" /> <ClInclude Include="ServerProperties.h" />
<ClInclude Include="vendor\linenoise\linenoise.h" /> <ClInclude Include="vendor\linenoise\linenoise.h" />
<ClInclude Include="WorldManager.h" /> <ClInclude Include="WorldManager.h" />

View file

@ -24,6 +24,9 @@
<ClCompile Include="ServerLogger.cpp"> <ClCompile Include="ServerLogger.cpp">
<Filter>Server</Filter> <Filter>Server</Filter>
</ClCompile> </ClCompile>
<ClCompile Include="ServerLogManager.cpp">
<Filter>Server</Filter>
</ClCompile>
<ClCompile Include="ServerProperties.cpp"> <ClCompile Include="ServerProperties.cpp">
<Filter>Server</Filter> <Filter>Server</Filter>
</ClCompile> </ClCompile>
@ -599,6 +602,9 @@
<ClInclude Include="ServerLogger.h"> <ClInclude Include="ServerLogger.h">
<Filter>Server</Filter> <Filter>Server</Filter>
</ClInclude> </ClInclude>
<ClInclude Include="ServerLogManager.h">
<Filter>Server</Filter>
</ClInclude>
<ClInclude Include="ServerProperties.h"> <ClInclude Include="ServerProperties.h">
<Filter>Server</Filter> <Filter>Server</Filter>
</ClInclude> </ClInclude>

View file

@ -0,0 +1,377 @@
#include "stdafx.h"
#include "ServerLogManager.h"
#include "Common\StringUtils.h"
#include "ServerLogger.h"
#include <array>
#include <mutex>
extern bool g_Win64DedicatedServer;
namespace ServerRuntime
{
namespace ServerLogManager
{
namespace
{
/**
* **!! This information is managed solely for logging purposes, but it is questionable from a liability perspective, so it will eventually need to be separated !!**
*
* Tracks the remote IP and accepted player name associated with one `smallId`
* 1smallIdに紐づく接続IPとプレイヤー名を保持する
*/
struct ConnectionLogEntry
{
std::string remoteIp;
std::string playerName;
};
/**
* Owns the shared connection cache used by hook points running on different threads
* hookから共有される接続キャッシュを保持する
*/
struct ServerLogState
{
std::mutex stateLock;
std::array<ConnectionLogEntry, 256> entries;
};
ServerLogState g_serverLogState;
static bool IsDedicatedServerLoggingEnabled()
{
return g_Win64DedicatedServer;
}
static void ResetConnectionLogEntry(ConnectionLogEntry *entry)
{
if (entry == NULL)
{
return;
}
entry->remoteIp.clear();
entry->playerName.clear();
}
static std::string NormalizeRemoteIp(const char *ip)
{
if (ip == NULL || ip[0] == 0)
{
return std::string("unknown");
}
return std::string(ip);
}
static std::string NormalizePlayerName(const std::wstring &playerName)
{
std::string playerNameUtf8 = StringUtils::WideToUtf8(playerName);
if (playerNameUtf8.empty())
{
playerNameUtf8 = "<unknown>";
}
return playerNameUtf8;
}
// Default to the main app channel when the caller does not provide a source tag.
static const char *NormalizeClientLogSource(const char *source)
{
if (source == NULL || source[0] == 0)
{
return "app";
}
return source;
}
static void EmitClientDebugLogLine(const char *source, const std::string &line)
{
if (line.empty())
{
return;
}
LogDebugf("client", "[%s] %s", NormalizeClientLogSource(source), line.c_str());
}
// Split one debug payload into individual lines so each line becomes a prompt-safe server log entry.
static void ForwardClientDebugMessage(const char *source, const char *message)
{
if (message == NULL || message[0] == 0)
{
return;
}
const char *cursor = message;
while (*cursor != 0)
{
const char *lineStart = cursor;
while (*cursor != 0 && *cursor != '\r' && *cursor != '\n')
{
++cursor;
}
// Split multi-line client debug output into prompt-safe server log entries.
if (cursor > lineStart)
{
EmitClientDebugLogLine(source, std::string(lineStart, (size_t)(cursor - lineStart)));
}
while (*cursor == '\r' || *cursor == '\n')
{
++cursor;
}
}
}
// Share the same formatting path for app, user, and legacy debug-spew forwards.
static void ForwardFormattedClientDebugLogV(const char *source, const char *format, va_list args)
{
if (!IsDedicatedServerLoggingEnabled() || format == NULL || format[0] == 0)
{
return;
}
char messageBuffer[2048] = {};
vsnprintf_s(messageBuffer, sizeof(messageBuffer), _TRUNCATE, format, args);
ForwardClientDebugMessage(source, messageBuffer);
}
static const char *TcpRejectReasonToString(ETcpRejectReason reason)
{
switch (reason)
{
case eTcpRejectReason_BannedIp: return "banned-ip";
case eTcpRejectReason_GameNotReady: return "game-not-ready";
case eTcpRejectReason_ServerFull: return "server-full";
default: return "unknown";
}
}
static const char *LoginRejectReasonToString(ELoginRejectReason reason)
{
switch (reason)
{
case eLoginRejectReason_BannedXuid: return "banned-xuid";
case eLoginRejectReason_DuplicateXuid: return "duplicate-xuid";
case eLoginRejectReason_DuplicateName: return "duplicate-name";
default: return "unknown";
}
}
static const char *DisconnectReasonToString(DisconnectPacket::eDisconnectReason reason)
{
switch (reason)
{
case DisconnectPacket::eDisconnect_None: return "none";
case DisconnectPacket::eDisconnect_Quitting: return "quitting";
case DisconnectPacket::eDisconnect_Closed: return "closed";
case DisconnectPacket::eDisconnect_LoginTooLong: return "login-too-long";
case DisconnectPacket::eDisconnect_IllegalStance: return "illegal-stance";
case DisconnectPacket::eDisconnect_IllegalPosition: return "illegal-position";
case DisconnectPacket::eDisconnect_MovedTooQuickly: return "moved-too-quickly";
case DisconnectPacket::eDisconnect_NoFlying: return "no-flying";
case DisconnectPacket::eDisconnect_Kicked: return "kicked";
case DisconnectPacket::eDisconnect_TimeOut: return "timeout";
case DisconnectPacket::eDisconnect_Overflow: return "overflow";
case DisconnectPacket::eDisconnect_EndOfStream: return "end-of-stream";
case DisconnectPacket::eDisconnect_ServerFull: return "server-full";
case DisconnectPacket::eDisconnect_OutdatedServer: return "outdated-server";
case DisconnectPacket::eDisconnect_OutdatedClient: return "outdated-client";
case DisconnectPacket::eDisconnect_UnexpectedPacket: return "unexpected-packet";
case DisconnectPacket::eDisconnect_ConnectionCreationFailed: return "connection-creation-failed";
case DisconnectPacket::eDisconnect_NoMultiplayerPrivilegesHost: return "no-multiplayer-privileges-host";
case DisconnectPacket::eDisconnect_NoMultiplayerPrivilegesJoin: return "no-multiplayer-privileges-join";
case DisconnectPacket::eDisconnect_NoUGC_AllLocal: return "no-ugc-all-local";
case DisconnectPacket::eDisconnect_NoUGC_Single_Local: return "no-ugc-single-local";
case DisconnectPacket::eDisconnect_ContentRestricted_AllLocal: return "content-restricted-all-local";
case DisconnectPacket::eDisconnect_ContentRestricted_Single_Local: return "content-restricted-single-local";
case DisconnectPacket::eDisconnect_NoUGC_Remote: return "no-ugc-remote";
case DisconnectPacket::eDisconnect_NoFriendsInGame: return "no-friends-in-game";
case DisconnectPacket::eDisconnect_Banned: return "banned";
case DisconnectPacket::eDisconnect_NotFriendsWithHost: return "not-friends-with-host";
case DisconnectPacket::eDisconnect_NATMismatch: return "nat-mismatch";
default: return "unknown";
}
}
}
// Only forward client-side debug output while the process is running as the dedicated server.
bool ShouldForwardClientDebugLogs()
{
return IsDedicatedServerLoggingEnabled();
}
void ForwardClientAppDebugLogV(const char *format, va_list args)
{
ForwardFormattedClientDebugLogV("app", format, args);
}
void ForwardClientUserDebugLogV(int user, const char *format, va_list args)
{
char source[32] = {};
_snprintf_s(source, sizeof(source), _TRUNCATE, "app:user=%d", user);
ForwardFormattedClientDebugLogV(source, format, args);
}
void ForwardClientDebugSpewLogV(const char *format, va_list args)
{
ForwardFormattedClientDebugLogV("debug-spew", format, args);
}
// Clear every cached connection slot during startup so stale metadata never leaks into future logs.
void Initialize()
{
std::lock_guard<std::mutex> stateLock(g_serverLogState.stateLock);
for (size_t index = 0; index < g_serverLogState.entries.size(); ++index)
{
ResetConnectionLogEntry(&g_serverLogState.entries[index]);
}
}
// Reuse Initialize as the shutdown cleanup path because both operations wipe the cache.
void Shutdown()
{
Initialize();
}
// Log the raw socket arrival before a smallId is assigned so early rejects still have an IP in the logs.
void OnIncomingTcpConnection(const char *ip)
{
if (!IsDedicatedServerLoggingEnabled())
{
return;
}
const std::string remoteIp = NormalizeRemoteIp(ip);
LogInfof("network", "incoming tcp connection from %s", remoteIp.c_str());
}
// TCP rejects happen before connection state is cached, so log directly from the supplied remote IP.
void OnRejectedTcpConnection(const char *ip, ETcpRejectReason reason)
{
if (!IsDedicatedServerLoggingEnabled())
{
return;
}
const std::string remoteIp = NormalizeRemoteIp(ip);
LogWarnf("network", "rejected tcp connection from %s: reason=%s", remoteIp.c_str(), TcpRejectReasonToString(reason));
}
// Cache the accepted remote IP immediately so later login and disconnect logs can reuse it.
void OnAcceptedTcpConnection(unsigned char smallId, const char *ip)
{
if (!IsDedicatedServerLoggingEnabled())
{
return;
}
const std::string remoteIp = NormalizeRemoteIp(ip);
{
std::lock_guard<std::mutex> stateLock(g_serverLogState.stateLock);
ConnectionLogEntry &entry = g_serverLogState.entries[smallId];
ResetConnectionLogEntry(&entry);
entry.remoteIp = remoteIp;
}
LogInfof("network", "accepted tcp connection from %s as smallId=%u", remoteIp.c_str(), (unsigned)smallId);
}
// Once login succeeds, bind the resolved player name onto the cached transport entry.
void OnAcceptedPlayerLogin(unsigned char smallId, const std::wstring &playerName)
{
if (!IsDedicatedServerLoggingEnabled())
{
return;
}
const std::string playerNameUtf8 = NormalizePlayerName(playerName);
std::string remoteIp("unknown");
{
std::lock_guard<std::mutex> stateLock(g_serverLogState.stateLock);
ConnectionLogEntry &entry = g_serverLogState.entries[smallId];
entry.playerName = playerNameUtf8;
if (!entry.remoteIp.empty())
{
remoteIp = entry.remoteIp;
}
}
LogInfof("network", "accepted player login: name=\"%s\" ip=%s smallId=%u", playerNameUtf8.c_str(), remoteIp.c_str(), (unsigned)smallId);
}
// Read the cached IP for the rejection log, then clear the slot because the player never fully joined.
void OnRejectedPlayerLogin(unsigned char smallId, const std::wstring &playerName, ELoginRejectReason reason)
{
if (!IsDedicatedServerLoggingEnabled())
{
return;
}
const std::string playerNameUtf8 = NormalizePlayerName(playerName);
std::string remoteIp("unknown");
{
std::lock_guard<std::mutex> stateLock(g_serverLogState.stateLock);
ConnectionLogEntry &entry = g_serverLogState.entries[smallId];
if (!entry.remoteIp.empty())
{
remoteIp = entry.remoteIp;
}
ResetConnectionLogEntry(&entry);
}
LogWarnf("network", "rejected login from %s: name=\"%s\" reason=%s", remoteIp.c_str(), playerNameUtf8.c_str(), LoginRejectReasonToString(reason));
}
// Disconnect logging is the final consumer of cached metadata, so it also clears the slot afterward.
void OnPlayerDisconnected(
unsigned char smallId,
const std::wstring &playerName,
DisconnectPacket::eDisconnectReason reason,
bool initiatedByServer)
{
if (!IsDedicatedServerLoggingEnabled())
{
return;
}
std::string playerNameUtf8 = NormalizePlayerName(playerName);
std::string remoteIp("unknown");
{
// Copy state under lock and emit the log after unlocking so CLI output never blocks connection bookkeeping.
std::lock_guard<std::mutex> stateLock(g_serverLogState.stateLock);
ConnectionLogEntry &entry = g_serverLogState.entries[smallId];
if (!entry.remoteIp.empty())
{
remoteIp = entry.remoteIp;
}
if (playerNameUtf8 == "<unknown>" && !entry.playerName.empty())
{
playerNameUtf8 = entry.playerName;
}
ResetConnectionLogEntry(&entry);
}
LogInfof(
"network",
"%s: name=\"%s\" ip=%s smallId=%u reason=%s",
initiatedByServer ? "disconnecting player" : "player disconnected",
playerNameUtf8.c_str(),
remoteIp.c_str(),
(unsigned)smallId,
DisconnectReasonToString(reason));
}
// Provide explicit cache cleanup for paths that terminate without going through disconnect logging.
void ClearConnection(unsigned char smallId)
{
std::lock_guard<std::mutex> stateLock(g_serverLogState.stateLock);
ResetConnectionLogEntry(&g_serverLogState.entries[smallId]);
}
}
}

View file

@ -0,0 +1,118 @@
#pragma once
#include <string>
#include <stdarg.h>
#include "..\Minecraft.World\DisconnectPacket.h"
namespace ServerRuntime
{
namespace ServerLogManager
{
/**
* Identifies why the dedicated server rejected a TCP connection before login completed
* TCP接続を拒否した理由
*/
enum ETcpRejectReason
{
eTcpRejectReason_BannedIp = 0,
eTcpRejectReason_GameNotReady,
eTcpRejectReason_ServerFull
};
/**
* Identifies why the dedicated server rejected a player during login validation
*
*/
enum ELoginRejectReason
{
eLoginRejectReason_BannedXuid = 0,
eLoginRejectReason_DuplicateXuid,
eLoginRejectReason_DuplicateName
};
/**
* Returns `true` when client-side debug logs should be redirected into the dedicated server logger
* dedicated server時にclient側デバッグログを転送すかどうか
*/
bool ShouldForwardClientDebugLogs();
/**
* Formats and forwards `CMinecraftApp::DebugPrintf` output through the dedicated server logger
* CMinecraftApp::DebugPrintf
*/
void ForwardClientAppDebugLogV(const char *format, va_list args);
/**
* Formats and forwards `CMinecraftApp::DebugPrintf(int user, ...)` output through the dedicated server logger
* CMinecraftApp::DebugPrintf(int user, ...)
*/
void ForwardClientUserDebugLogV(int user, const char *format, va_list args);
/**
* Formats and forwards legacy `DebugSpew` output through the dedicated server logger
* DebugSpew
*/
void ForwardClientDebugSpewLogV(const char *format, va_list args);
/**
* Clears cached connection metadata before the dedicated server starts accepting players
*
*/
void Initialize();
/**
* Releases cached connection metadata after the dedicated server stops
*
*/
void Shutdown();
/**
* **Log Incoming TCP Connection**
*
* Emits a named log for a raw TCP accept before smallId assignment finishes
* smallId割り当て前のTCP接続を記録
*/
void OnIncomingTcpConnection(const char *ip);
/**
* Emits a named log for a TCP connection rejected before login starts
* TCP接続を記録
*/
void OnRejectedTcpConnection(const char *ip, ETcpRejectReason reason);
/**
* Stores the remote IP for the assigned smallId and logs the accepted transport connection
* smallIdに対接続IPを保存して記録
*/
void OnAcceptedTcpConnection(unsigned char smallId, const char *ip);
/**
* Associates a player name with the connection and emits the accepted login log
*
*/
void OnAcceptedPlayerLogin(unsigned char smallId, const std::wstring &playerName);
/**
* Emits a named login rejection log and clears cached metadata for that smallId
* smallIdのキャッシュを破棄
*/
void OnRejectedPlayerLogin(unsigned char smallId, const std::wstring &playerName, ELoginRejectReason reason);
/**
* Emits a named disconnect log using cached connection metadata and then clears that entry
* 使
*/
void OnPlayerDisconnected(
unsigned char smallId,
const std::wstring &playerName,
DisconnectPacket::eDisconnectReason reason,
bool initiatedByServer);
/**
* Removes any remembered IP or player name for the specified smallId
* smallIdに紐づく接続キャッシュを消去
*/
void ClearConnection(unsigned char smallId);
}
}

View file

@ -8,6 +8,7 @@
#include "..\Access\Access.h" #include "..\Access\Access.h"
#include "..\Common\StringUtils.h" #include "..\Common\StringUtils.h"
#include "..\ServerLogger.h" #include "..\ServerLogger.h"
#include "..\ServerLogManager.h"
#include "..\ServerProperties.h" #include "..\ServerProperties.h"
#include "..\WorldManager.h" #include "..\WorldManager.h"
#include "..\Console\ServerCli.h" #include "..\Console\ServerCli.h"
@ -369,6 +370,8 @@ int main(int argc, char **argv)
g_Win64DedicatedServerPort = config.port; g_Win64DedicatedServerPort = config.port;
strncpy_s(g_Win64DedicatedServerBindIP, sizeof(g_Win64DedicatedServerBindIP), config.bindIP, _TRUNCATE); strncpy_s(g_Win64DedicatedServerBindIP, sizeof(g_Win64DedicatedServerBindIP), config.bindIP, _TRUNCATE);
g_Win64DedicatedServerLanAdvertise = serverProperties.lanAdvertise; g_Win64DedicatedServerLanAdvertise = serverProperties.lanAdvertise;
LogStartupStep("initializing server log manager");
ServerRuntime::ServerLogManager::Initialize();
LogStartupStep("initializing dedicated access control"); LogStartupStep("initializing dedicated access control");
if (!ServerRuntime::Access::Initialize(".")) if (!ServerRuntime::Access::Initialize("."))
{ {
@ -653,6 +656,7 @@ int main(int argc, char **argv)
WinsockNetLayer::Shutdown(); WinsockNetLayer::Shutdown();
g_NetworkManager.Terminate(); g_NetworkManager.Terminate();
ServerRuntime::ServerLogManager::Shutdown();
CleanupDevice(); CleanupDevice();