From 60995b1933ff94757d2d29629f324d16070de1ea Mon Sep 17 00:00:00 2001 From: Maxim Mamontov Date: Thu, 14 Nov 2013 21:52:16 +0200 Subject: [PATCH] Implemented IA protocol errors logging. --- include/stg/users.h | 4 +- include/stg/utime.h | 5 ++ .../authorization/inetaccess/inetaccess.cpp | 77 ++++++++++++++++--- .../authorization/inetaccess/inetaccess.h | 4 +- projects/stargazer/user_impl.cpp | 10 ++- projects/stargazer/user_impl.h | 4 +- projects/stargazer/users_impl.cpp | 6 +- projects/stargazer/users_impl.h | 4 +- 8 files changed, 97 insertions(+), 17 deletions(-) diff --git a/include/stg/users.h b/include/stg/users.h index b97a9be5..765fc14d 100644 --- a/include/stg/users.h +++ b/include/stg/users.h @@ -46,7 +46,9 @@ public: virtual bool Authorize(const std::string & login, uint32_t ip, uint32_t enabledDirs, const AUTH * auth) = 0; - virtual bool Unauthorize(const std::string & login, const AUTH * auth) = 0; + virtual bool Unauthorize(const std::string & login, + const AUTH * auth, + const std::string & reason = std::string()) = 0; virtual int ReadUsers() = 0; virtual size_t Count() const = 0; diff --git a/include/stg/utime.h b/include/stg/utime.h index 20da4e43..fe6b3f69 100644 --- a/include/stg/utime.h +++ b/include/stg/utime.h @@ -164,6 +164,11 @@ struct UTIME: public timeval { return tv_usec; } + + double AsDouble() const + { + return tv_sec + tv_usec * 1e-6; + } }; diff --git a/projects/stargazer/plugins/authorization/inetaccess/inetaccess.cpp b/projects/stargazer/plugins/authorization/inetaccess/inetaccess.cpp index dd0102b2..5a15a10a 100644 --- a/projects/stargazer/plugins/authorization/inetaccess/inetaccess.cpp +++ b/projects/stargazer/plugins/authorization/inetaccess/inetaccess.cpp @@ -134,6 +134,17 @@ if (ParseIntInRange(pvi->value[0], 15, 1200, &userTimeout)) printfd(__FILE__, "Cannot parse parameter 'UserTimeout'\n"); return -1; } +/////////////////////////// +pv.param = "LogProtocolErrors"; +pvi = find(s.moduleParams.begin(), s.moduleParams.end(), pv); +if (pvi == s.moduleParams.end()) + logProtocolErrors = false; +else if (ParseYesNo(pvi->value[0], &logProtocolErrors)) + { + errorStr = "Cannot parse parameter \'LogProtocolErrors\': " + errorStr; + printfd(__FILE__, "Cannot parse parameter 'LogProtocolErrors'\n"); + return -1; + } ///////////////////////////////////////////////////////////// std::string freeMbType; int n = 0; @@ -590,8 +601,11 @@ if (dataLen <= 0) // Error if (dataLen > 256) return -1; +uint32_t sip = outerAddr.sin_addr.s_addr; +uint16_t sport = htons(outerAddr.sin_port); + int protoVer; -if (CheckHeader(buffer, &protoVer)) +if (CheckHeader(buffer, sip, &protoVer)) return -1; char login[PASSWD_LEN]; //TODO why PASSWD_LEN ? @@ -599,9 +613,6 @@ memset(login, 0, PASSWD_LEN); Decrypt(&ctxS, login, buffer + 8, PASSWD_LEN / 8); -uint32_t sip = outerAddr.sin_addr.s_addr; -uint16_t sport = htons(outerAddr.sin_port); - USER_PTR user; if (users->FindByName(login, &user)) { @@ -642,12 +653,14 @@ if (!user->GetProperty().ips.Get().IsIPInIPS(sip)) return PacketProcessor(buffer, dataLen, sip, sport, protoVer, user); } //----------------------------------------------------------------------------- -int AUTH_IA::CheckHeader(const char * buffer, int * protoVer) +int AUTH_IA::CheckHeader(const char * buffer, uint32_t sip, int * protoVer) { if (strncmp(IA_ID, buffer, strlen(IA_ID)) != 0) { //SendError(userIP, updateMsg); printfd(__FILE__, "update needed - IA_ID\n"); + if (iaSettings.LogProtocolErrors()) + logger("IP: %s. Header: invalid packed signature.", inet_ntostring(sip).c_str()); //SendError(userIP, "Incorrect header!"); return -1; } @@ -655,6 +668,8 @@ if (strncmp(IA_ID, buffer, strlen(IA_ID)) != 0) if (buffer[6] != 0) //proto[0] shoud be 0 { printfd(__FILE__, "update needed - PROTO major: %d\n", buffer[6]); + if (iaSettings.LogProtocolErrors()) + logger("IP: %s. Header: invalid protocol major version: %d.", inet_ntostring(sip).c_str(), buffer[6]); //SendError(userIP, updateMsg); return -1; } @@ -664,6 +679,8 @@ if (buffer[7] < 6) // need update //SendError(userIP, updateMsg); printfd(__FILE__, "update needed - PROTO minor: %d\n", buffer[7]); + if (iaSettings.LogProtocolErrors()) + logger("IP: %s. Header: invalid protocol minor version: %d.", inet_ntostring(sip).c_str(), buffer[7]); return -1; } else @@ -691,6 +708,8 @@ while (it != ip2user.end()) if ((it->second.phase.GetPhase() == 2) && (currTime - it->second.phase.GetTime()) > iaSettings.GetUserDelay()) { + if (iaSettings.LogProtocolErrors()) + logger("User '%s'. Protocol version: %d. Phase 2: connect request timeout (%f > %d).", it->second.login.c_str(), it->second.protoVer, (currTime - it->second.phase.GetTime()).AsDouble(), iaSettings.GetUserDelay()); it->second.phase.SetPhase1(); printfd(__FILE__, "Phase changed from 2 to 1. Reason: timeout\n"); ip2user.erase(it++); @@ -733,6 +752,8 @@ while (it != ip2user.end()) if ((currTime - it->second.phase.GetTime()) > iaSettings.GetUserTimeout()) { + if (iaSettings.LogProtocolErrors()) + logger("User '%s'. Protocol version: %d. Phase 3: alive timeout (%f > %d).", it->second.login.c_str(), it->second.protoVer, (currTime - it->second.phase.GetTime()).AsDouble(), iaSettings.GetUserTimeout()); users->Unauthorize(it->second.user->GetLogin(), this); ip2user.erase(it++); continue; @@ -742,6 +763,8 @@ while (it != ip2user.end()) if ((it->second.phase.GetPhase() == 4) && ((currTime - it->second.phase.GetTime()) > iaSettings.GetUserDelay())) { + if (iaSettings.LogProtocolErrors()) + logger("User '%s'. Protocol version: %d. Phase 4: disconnect request timeout (%f > %d).", it->second.login.c_str(), it->second.protoVer, (currTime - it->second.phase.GetTime()).AsDouble(), iaSettings.GetUserDelay()); it->second.phase.SetPhase3(); printfd(__FILE__, "Phase changed from 4 to 3. Reason: timeout\n"); } @@ -1174,6 +1197,8 @@ if ((iaUser->phase.GetPhase() == 2) && (connAck->rnd == iaUser->rnd + 1)) else { errorStr = iaUser->user->GetStrError(); + if (iaSettings.LogProtocolErrors()) + logger("IP: %s. User '%s'. Protocol version: %d. CONN_ACK: phase 2, authorization error ('%s').", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, errorStr.c_str()); iaUser->phase.SetPhase1(); ip2user.erase(sip); printfd(__FILE__, "Phase changed from 2 to 1. Reason: failed to authorize user\n"); @@ -1181,6 +1206,13 @@ if ((iaUser->phase.GetPhase() == 2) && (connAck->rnd == iaUser->rnd + 1)) } } printfd(__FILE__, "Invalid phase or control number. Phase: %d. Control number: %d\n", iaUser->phase.GetPhase(), connAck->rnd); +if (iaSettings.LogProtocolErrors()) + { + if (iaUser->phase.GetPhase() != 2) + logger("IP: %s. User '%s'. Protocol version: %d. CONN_ACK: invalid phase, expected 2, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, iaUser->phase.GetPhase()); + if (connAck->rnd != iaUser->rnd + 1) + logger("IP: %s. User '%s'. Protocol version: %d. CONN_ACK: invalid control number, expected %d, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, (iaUser->rnd + 1), connAck->rnd); + } return -1; } //----------------------------------------------------------------------------- @@ -1210,6 +1242,8 @@ if ((iaUser->phase.GetPhase() == 2) && (connAck->rnd == iaUser->rnd + 1)) else { errorStr = iaUser->user->GetStrError(); + if (iaSettings.LogProtocolErrors()) + logger("IP: %s. User '%s'. Protocol version: %d. CONN_ACK: phase 2, authorization error ('%s').", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, errorStr.c_str()); iaUser->phase.SetPhase1(); ip2user.erase(sip); printfd(__FILE__, "Phase changed from 2 to 1. Reason: failed to authorize user\n"); @@ -1217,6 +1251,13 @@ if ((iaUser->phase.GetPhase() == 2) && (connAck->rnd == iaUser->rnd + 1)) } } printfd(__FILE__, "Invalid phase or control number. Phase: %d. Control number: %d\n", iaUser->phase.GetPhase(), connAck->rnd); +if (iaSettings.LogProtocolErrors()) + { + if (iaUser->phase.GetPhase() != 2) + logger("IP: %s. User '%s'. Protocol version: %d. CONN_ACK: invalid phase, expected 2, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, iaUser->phase.GetPhase()); + if (connAck->rnd != iaUser->rnd + 1) + logger("IP: %s. User '%s'. Protocol version: %d. CONN_ACK: invalid control number, expected %d, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, (iaUser->rnd + 1), connAck->rnd); + } return -1; } //----------------------------------------------------------------------------- @@ -1259,11 +1300,13 @@ if ((iaUser->phase.GetPhase() == 3) && (aliveAck->rnd == iaUser->rnd + 1)) return 0; } //----------------------------------------------------------------------------- -int AUTH_IA::Process_DISCONN_SYN_6(DISCONN_SYN_6 *, IA_USER * iaUser, uint32_t) +int AUTH_IA::Process_DISCONN_SYN_6(DISCONN_SYN_6 *, IA_USER * iaUser, uint32_t sip) { printfd(__FILE__, "DISCONN_SYN_6\n"); if (iaUser->phase.GetPhase() != 3) { + if (iaSettings.LogProtocolErrors()) + logger("IP: %s. User '%s'. Protocol version: %d. DISCONN_SYN: invalid phase, expected 3, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, iaUser->phase.GetPhase()); printfd(__FILE__, "Invalid phase. Expected 3, actual %d\n", iaUser->phase.GetPhase()); errorStr = "Incorrect request DISCONN_SYN"; return -1; @@ -1280,10 +1323,12 @@ int AUTH_IA::Process_DISCONN_SYN_7(DISCONN_SYN_7 * disconnSyn, IA_USER * iaUser, return Process_DISCONN_SYN_6(disconnSyn, iaUser, sip); } //----------------------------------------------------------------------------- -int AUTH_IA::Process_DISCONN_SYN_8(DISCONN_SYN_8 *, IA_USER * iaUser, uint32_t) +int AUTH_IA::Process_DISCONN_SYN_8(DISCONN_SYN_8 *, IA_USER * iaUser, uint32_t sip) { if (iaUser->phase.GetPhase() != 3) { + if (iaSettings.LogProtocolErrors()) + logger("IP: %s. User '%s'. Protocol version: %d. DISCONN_SYN: invalid phase, expected 3, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, iaUser->phase.GetPhase()); errorStr = "Incorrect request DISCONN_SYN"; printfd(__FILE__, "Invalid phase. Expected 3, actual %d\n", iaUser->phase.GetPhase()); return -1; @@ -1297,7 +1342,7 @@ return 0; //----------------------------------------------------------------------------- int AUTH_IA::Process_DISCONN_ACK_6(DISCONN_ACK_6 * disconnAck, IA_USER * iaUser, - uint32_t, + uint32_t sip, std::map::iterator) { #ifdef ARCH_BE @@ -1307,6 +1352,13 @@ SwapBytes(disconnAck->rnd); printfd(__FILE__, "DISCONN_ACK_6\n"); if (!((iaUser->phase.GetPhase() == 4) && (disconnAck->rnd == iaUser->rnd + 1))) { + if (iaSettings.LogProtocolErrors()) + { + if (iaUser->phase.GetPhase() != 4) + logger("IP: %s. User '%s'. Protocol version: %d. DISCONN_ACK: invalid phase, expected 4, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, iaUser->phase.GetPhase()); + if (disconnAck->rnd != iaUser->rnd + 1) + logger("IP: %s. User '%s'. Protocol version: %d. DISCONN_ACK: invalid control number, expected %d, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, (iaUser->rnd + 1), disconnAck->rnd); + } printfd(__FILE__, "Invalid phase or control number. Phase: %d. Control number: %d\n", iaUser->phase.GetPhase(), disconnAck->rnd); return -1; } @@ -1319,7 +1371,7 @@ int AUTH_IA::Process_DISCONN_ACK_7(DISCONN_ACK_7 * disconnAck, IA_USER * iaUser, return Process_DISCONN_ACK_6(disconnAck, iaUser, sip, it); } //----------------------------------------------------------------------------- -int AUTH_IA::Process_DISCONN_ACK_8(DISCONN_ACK_8 * disconnAck, IA_USER * iaUser, uint32_t, std::map::iterator) +int AUTH_IA::Process_DISCONN_ACK_8(DISCONN_ACK_8 * disconnAck, IA_USER * iaUser, uint32_t sip, std::map::iterator) { #ifdef ARCH_BE SwapBytes(disconnAck->len); @@ -1328,6 +1380,13 @@ SwapBytes(disconnAck->rnd); printfd(__FILE__, "DISCONN_ACK_8\n"); if (!((iaUser->phase.GetPhase() == 4) && (disconnAck->rnd == iaUser->rnd + 1))) { + if (iaSettings.LogProtocolErrors()) + { + if (iaUser->phase.GetPhase() != 4) + logger("IP: %s. User '%s'. Protocol version: %d. DISCONN_ACK: invalid phase, expected 4, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, iaUser->phase.GetPhase()); + if (disconnAck->rnd != iaUser->rnd + 1) + logger("IP: %s. User '%s'. Protocol version: %d. DISCONN_ACK: invalid control number, expected %d, got %d.", inet_ntostring(sip).c_str(), iaUser->login.c_str(), iaUser->protoVer, (iaUser->rnd + 1), disconnAck->rnd); + } printfd(__FILE__, "Invalid phase or control number. Phase: %d. Control number: %d\n", iaUser->phase.GetPhase(), disconnAck->rnd); return -1; } diff --git a/projects/stargazer/plugins/authorization/inetaccess/inetaccess.h b/projects/stargazer/plugins/authorization/inetaccess/inetaccess.h index a13a11db..87350556 100644 --- a/projects/stargazer/plugins/authorization/inetaccess/inetaccess.h +++ b/projects/stargazer/plugins/authorization/inetaccess/inetaccess.h @@ -209,6 +209,7 @@ public: int GetUserTimeout() const { return userTimeout; } uint16_t GetUserPort() const { return port; } FREEMB GetFreeMbShowType() const { return freeMbShowType; } + bool LogProtocolErrors() const { return logProtocolErrors; } private: int userDelay; @@ -216,6 +217,7 @@ private: uint16_t port; std::string errorStr; FREEMB freeMbShowType; + bool logProtocolErrors; }; //----------------------------------------------------------------------------- class AUTH_IA; @@ -266,7 +268,7 @@ private: int FinalizeNet(); void DelUser(USER_PTR u); int RecvData(char * buffer, int bufferSize); - int CheckHeader(const char * buffer, int * protoVer); + int CheckHeader(const char * buffer, uint32_t sip, int * protoVer); int PacketProcessor(void * buff, size_t dataLen, uint32_t sip, uint16_t sport, int protoVer, USER_PTR user); int Process_CONN_SYN_6(CONN_SYN_6 * connSyn, IA_USER * iaUser, uint32_t sip); diff --git a/projects/stargazer/user_impl.cpp b/projects/stargazer/user_impl.cpp index 5bb0069f..37178dd6 100644 --- a/projects/stargazer/user_impl.cpp +++ b/projects/stargazer/user_impl.cpp @@ -544,7 +544,7 @@ ScanMessage(); return 0; } //----------------------------------------------------------------------------- -void USER_IMPL::Unauthorize(const AUTH * auth) +void USER_IMPL::Unauthorize(const AUTH * auth, const std::string & reason) { STG_LOCKER lock(&mutex, __FILE__, __LINE__); /* @@ -555,6 +555,7 @@ if (!authorizedBy.erase(auth)) if (authorizedBy.empty()) { + lastDisconnectReason = reason; lastIPForDisconnect = currIP; currIP = 0; // DelUser in traffcounter return; @@ -673,7 +674,12 @@ if (!fakeDisconnect) connected = false; } -if (store->WriteUserDisconnect(login, up, down, sessionUpload, sessionDownload, cash, freeMb, reason)) +std::string reasonMessage(reason); +if (!lastDisconnectReason.empty()) + reasonMessage += ": " + lastDisconnectReason; + +if (store->WriteUserDisconnect(login, up, down, sessionUpload, sessionDownload, + cash, freeMb, reasonMessage)) { WriteServLog("Cannot write disconnect for user %s.", login.c_str()); WriteServLog("%s", store->GetStrError().c_str()); diff --git a/projects/stargazer/user_impl.h b/projects/stargazer/user_impl.h index a581f2e5..6f6030ca 100644 --- a/projects/stargazer/user_impl.h +++ b/projects/stargazer/user_impl.h @@ -185,7 +185,8 @@ public: time_t GetConnectedModificationTime() const { return connected.ModificationTime(); } int GetAuthorized() const { return static_cast(authorizedBy.size()); } int Authorize(uint32_t ip, uint32_t enabledDirs, const AUTH * auth); - void Unauthorize(const AUTH * auth); + void Unauthorize(const AUTH * auth, + const std::string & reason = std::string()); bool IsAuthorizedBy(const AUTH * auth) const; std::vector GetAuthorizers() const; @@ -249,6 +250,7 @@ private: USER_PROPERTY currIP; uint32_t lastIPForDisconnect; // User's ip after unauth but before disconnect + std::string lastDisconnectReason; time_t pingTime; diff --git a/projects/stargazer/users_impl.cpp b/projects/stargazer/users_impl.cpp index c4f63c64..97b4bbbc 100644 --- a/projects/stargazer/users_impl.cpp +++ b/projects/stargazer/users_impl.cpp @@ -298,7 +298,9 @@ AddToIPIdx(iter); return true; } //----------------------------------------------------------------------------- -bool USERS_IMPL::Unauthorize(const std::string & login, const AUTH * auth) +bool USERS_IMPL::Unauthorize(const std::string & login, + const AUTH * auth, + const std::string & reason) { user_iter iter; STG_LOCKER lock(&mutex, __FILE__, __LINE__); @@ -310,7 +312,7 @@ if (FindByNameNonLock(login, &iter)) uint32_t ip = iter->GetCurrIP(); -iter->Unauthorize(auth); +iter->Unauthorize(auth, reason); if (!iter->GetAuthorized()) DelFromIPIdx(ip); diff --git a/projects/stargazer/users_impl.h b/projects/stargazer/users_impl.h index 0c2af78d..70a5b9bd 100644 --- a/projects/stargazer/users_impl.h +++ b/projects/stargazer/users_impl.h @@ -95,7 +95,9 @@ public: bool Authorize(const std::string & login, uint32_t ip, uint32_t enabledDirs, const AUTH * auth); - bool Unauthorize(const std::string & login, const AUTH * auth); + bool Unauthorize(const std::string & login, + const AUTH * auth, + const std::string & reason = std::string()); int ReadUsers(); size_t Count() const { return users.size(); } -- 2.44.2