Revert "Core/Logging: Use logger cache for speed up logger filter search"

This reverts commit 39331ea7b9.
This is required to fix a race condition introduced with the logger cache. Adding a locking mechanism might make worthless the speed gain added by the cache itself, push a proper thread-safe implementation if it's worth it.

Helgrind log:
Possible data race during write of size 8 at 0x736F428 by thread #1
Locks held: none
   at 0x11872DF: std::_Hashtable<std::string, std::pair<std::string const, Logger const*>, std::allocator<std::pair<std::string const, Logger const*> >, std::__detail::_Select1st, std::equal_to<std::string>, std::hash<std::string>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::_M_insert_bucket_begin(unsigned long, std::__detail::_Hash_node<std::pair<std::string const, Logger const*>, true>*) (hashtable.h:1196)
   by 0x11865A1: std::_Hashtable<std::string, std::pair<std::string const, Logger const*>, std::allocator<std::pair<std::string const, Logger const*> >, std::__detail::_Select1st, std::equal_to<std::string>, std::hash<std::string>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::_M_insert_unique_node(unsigned long, unsigned long, std::__detail::_Hash_node<std::pair<std::string const, Logger const*>, true>*) (hashtable.h:1342)
   by 0x1185A48: std::__detail::_Map_base<std::string, std::pair<std::string const, Logger const*>, std::allocator<std::pair<std::string const, Logger const*> >, std::__detail::_Select1st, std::equal_to<std::string>, std::hash<std::string>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true>, true>::operator[](std::string const&) (hashtable_policy.h:496)
   by 0x1184F3A: std::unordered_map<std::string, Logger const*, std::hash<std::string>, std::equal_to<std::string>, std::allocator<std::pair<std::string const, Logger const*> > >::operator[](std::string const&) (unordered_map.h:596)
   by 0x1184495: Log::GetLoggerByType(std::string const&) (Log.h:106)
   by 0x1184527: Log::ShouldLog(std::string const&, LogLevel) (Log.h:112)
   by 0x16E7121: World::LoadConfigSettings(bool) (World.cpp:909)
   by 0x16EB623: World::SetInitialWorldSettings() (World.cpp:1276)
   by 0x118F0EC: Master::Run() (Master.cpp:169)
   by 0x1196AFF: main (Main.cpp:142)

This conflicts with a previous read of size 8 by thread #3
Locks held: none
   at 0x1186EA6: std::_Hashtable<std::string, std::pair<std::string const, Logger const*>, std::allocator<std::pair<std::string const, Logger const*> >, std::__detail::_Select1st, std::equal_to<std::string>, std::hash<std::string>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::_M_find_before_node(unsigned long, std::string const&, unsigned long) const (hashtable.h:1162)
   by 0x1186263: std::_Hashtable<std::string, std::pair<std::string const, Logger const*>, std::allocator<std::pair<std::string const, Logger const*> >, std::__detail::_Select1st, std::equal_to<std::string>, std::hash<std::string>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::_M_find_node(unsigned long, std::string const&, unsigned long) const (hashtable.h:604)
   by 0x11857B9: std::_Hashtable<std::string, std::pair<std::string const, Logger const*>, std::allocator<std::pair<std::string const, Logger const*> >, std::__detail::_Select1st, std::equal_to<std::string>, std::hash<std::string>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<true, false, true> >::find(std::string const&) (hashtable.h:1025)
   by 0x1184DE2: std::unordered_map<std::string, Logger const*, std::hash<std::string>, std::equal_to<std::string>, std::allocator<std::pair<std::string const, Logger const*> > >::find(std::string const&) (unordered_map.h:543)
   by 0x11842EF: Log::GetLoggerByType(std::string const&) (Log.h:84)
   by 0x1184527: Log::ShouldLog(std::string const&, LogLevel) (Log.h:112)
   by 0x189AACA: MySQLConnection::Execute(char const*) (MySQLConnection.cpp:175)
   by 0x18A3225: BasicStatementTask::Execute() (AdhocStatement.cpp:56)

Address 0x736F428 is 120 bytes inside a block of size 184 alloc'd
   at 0x4C2AE3A: operator new(unsigned long, std::nothrow_t const&) (vg_replace_malloc.c:350)
   by 0x1185046: ACE_Singleton<Log, ACE_Thread_Mutex>::instance() (Singleton.cpp:91)
   by 0x11968E2: main (Main.cpp:135)
This commit is contained in:
jackpoz
2014-05-18 16:19:16 +02:00
parent 0904858624
commit 7228bd3664
2 changed files with 16 additions and 31 deletions

View File

@@ -267,7 +267,7 @@ void Log::vlog(std::string const& filter, LogLevel level, char const* str, va_li
write(new LogMessage(level, filter, text));
}
void Log::write(LogMessage* msg)
void Log::write(LogMessage* msg) const
{
Logger const* logger = GetLoggerByType(msg->type);
msg->text.append("\n");
@@ -376,7 +376,6 @@ void Log::Close()
delete worker;
worker = NULL;
loggers.clear();
cachedLoggers.clear();
for (AppenderMap::iterator it = appenders.begin(); it != appenders.end(); ++it)
{
delete it->second;

View File

@@ -35,7 +35,6 @@ class Log
friend class ACE_Singleton<Log, ACE_Thread_Mutex>;
typedef std::unordered_map<std::string, Logger> LoggerMap;
typedef std::unordered_map<std::string, Logger const*> CachedLoggerContainer;
private:
Log();
@@ -44,7 +43,7 @@ class Log
public:
void LoadFromConfig();
void Close();
bool ShouldLog(std::string const& type, LogLevel level);
bool ShouldLog(std::string const& type, LogLevel level) const;
bool SetLogLevel(std::string const& name, char const* level, bool isLogger = true);
void outMessage(std::string const& f, LogLevel level, char const* str, ...) ATTR_PRINTF(4, 5);
@@ -57,9 +56,9 @@ class Log
private:
static std::string GetTimestampStr();
void vlog(std::string const& f, LogLevel level, char const* str, va_list argptr);
void write(LogMessage* msg);
void write(LogMessage* msg) const;
Logger const* GetLoggerByType(std::string const& type);
Logger const* GetLoggerByType(std::string const& type) const;
Appender* GetAppenderByName(std::string const& name);
uint8 NextAppenderId();
void CreateAppenderFromConfig(std::string const& name);
@@ -69,7 +68,6 @@ class Log
AppenderMap appenders;
LoggerMap loggers;
CachedLoggerContainer cachedLoggers;
uint8 AppenderId;
std::string m_logsDir;
@@ -78,36 +76,24 @@ class Log
LogWorker* worker;
};
inline Logger const* Log::GetLoggerByType(std::string const& originalType)
inline Logger const* Log::GetLoggerByType(std::string const& type) const
{
// Check if already cached
CachedLoggerContainer::const_iterator itCached = cachedLoggers.find(originalType);
if (itCached != cachedLoggers.end())
return itCached->second;
LoggerMap::const_iterator it = loggers.find(type);
if (it != loggers.end())
return &(it->second);
Logger const* logger = NULL;
std::string type(originalType);
if (type == LOGGER_ROOT)
return NULL;
do
{
// Search for the logger "type.subtype"
LoggerMap::const_iterator it = loggers.find(type);
if (it == loggers.end())
{
// Search for the logger "type", if our logger contains '.', otherwise search for LOGGER_ROOT
size_t found = type.find_last_of(".");
type = found != std::string::npos ? type.substr(0, found) : LOGGER_ROOT;
}
else
logger = &(it->second);
}
while (!logger);
std::string parentLogger = LOGGER_ROOT;
size_t found = type.find_last_of(".");
if (found != std::string::npos)
parentLogger = type.substr(0,found);
cachedLoggers[type] = logger;
return logger;
return GetLoggerByType(parentLogger);
}
inline bool Log::ShouldLog(std::string const& type, LogLevel level)
inline bool Log::ShouldLog(std::string const& type, LogLevel level) const
{
// TODO: Use cache to store "Type.sub1.sub2": "Type" equivalence, should
// Speed up in cases where requesting "Type.sub1.sub2" but only configured