[fix] Fix issue where custom logger setting is ignored

[massakam]

Motivation

I noticed that there are cases where the specified logger factory is not used. For example, if we compile and run the following code, it expects FileLoggerFactory to be used, but it actually uses the default ConsoleLoggerFactory.

ClientConfiguration config = ClientConfiguration();
config.setLogger(new FileLoggerFactory(Logger::LEVEL_INFO, "pulsar-client-cpp.log"));

ParamMap params;
params["providerDomain"]    = "provider.foo.bar";
params["tenantDomain"]      = "tenant.foo.bar";
params["tenantService"]     = "test-service";
params["privateKey"]        = "file:///path/to/private.key";
params["keyId"]             = "0";
params["ztsUrl"]            = "https://zts.athenz.example.com:443";

AuthenticationPtr auth = AuthAthenz::create(params);
config.setAuth(auth);

Client client("pulsar://localhost:6650", config);

This happens if logging is performed before LogUtils::setLoggerFactory is executed in the constructor of ClientImpl.

pulsar-client-cpp/lib/ClientImpl.cc

Lines 94 to 99 in 25ea451

	std::unique_ptr<LoggerFactory> loggerFactory = clientConfiguration_.impl_->takeLogger();
	if (!loggerFactory) {
	// Use default simple console logger
	loggerFactory.reset(new ConsoleLoggerFactory);
	}
	LogUtils::setLoggerFactory(std::move(loggerFactory));

When logging is performed, LogUtils::getLoggerFactory is called.

1. pulsar-client-cpp/lib/LogUtils.h

   Line 60 in 25ea451

   if (logger()->isEnabled(pulsar::Logger::LEVEL_INFO)) { \

2. pulsar-client-cpp/lib/LogUtils.h

   Line 43 in 25ea451

   threadSpecificLogPtr.reset(pulsar::LogUtils::getLoggerFactory()->getLogger(logger)); \

If the constructor of ClientImpl has not been executed at this point, the default ConsoleLoggerFactory is instantiated, set to the static variable s_loggerFactory, and returned to the caller.

pulsar-client-cpp/lib/LogUtils.cc

Lines 38 to 44 in 25ea451

	LoggerFactory* LogUtils::getLoggerFactory() {
	if (s_loggerFactory.load() == nullptr) {
	std::unique_ptr<LoggerFactory> newFactory(new ConsoleLoggerFactory());
	setLoggerFactory(std::move(newFactory));
	}
	return s_loggerFactory.load();
	}

Loggers generated from the returned LoggerFactory will be set to the static and thread_local variable threadSpecificLogPtr, and reused from now on.

pulsar-client-cpp/lib/LogUtils.h

Lines 38 to 47 in 25ea451

	static pulsar::Logger* logger() { \
	static thread_local std::unique_ptr<pulsar::Logger> threadSpecificLogPtr; \
	pulsar::Logger* ptr = threadSpecificLogPtr.get(); \
	if (PULSAR_UNLIKELY(!ptr)) { \
	std::string logger = pulsar::LogUtils::getLoggerName(__FILE__); \
	threadSpecificLogPtr.reset(pulsar::LogUtils::getLoggerFactory()->getLogger(logger)); \
	ptr = threadSpecificLogPtr.get(); \
	} \
	return ptr; \
	}

After that, LogUtils::setLoggerFactory is executed again in the constructor of ClientImpl, but the value can only be set to s_loggerFactory once, and it will be ignored from the second time. This is clearly stated in the comments.

pulsar-client-cpp/lib/LogUtils.cc

Lines 30 to 36 in 25ea451

	void LogUtils::setLoggerFactory(std::unique_ptr<LoggerFactory> loggerFactory) {
	LoggerFactory* oldFactory = nullptr;
	LoggerFactory* newFactory = loggerFactory.release();
	if (!s_loggerFactory.compare_exchange_strong(oldFactory, newFactory)) {
	delete newFactory; // there's already a factory set
	}
	}

Even if we can set it again, if a logger is already set to threadSpecificLogPtr, a new logger will not be generated from the new LoggerFactory.

Modifications

Keep an instance of the default ConsoleLoggerFactory in s_defaultLoggerFactory, a variable separate from s_loggerFactory, and return it if LoggerFactory is not set yet.

In addition, keep the pointer value of the LoggerFactory that generated the logger cached in threadSpecificLogPtr, and regenerate the logger if the LoggerFactory pointer changes.

Verifying this change

• Make sure that the change passes the CI checks.

Documentation

• doc-not-needed

[BewareMyPower]

The s_defaultLoggerFactory is never released. It's not an issue if the application only run once, but if this library is dynamically loaded by an external system, it will be a memory leak.

Could a static logger factory be used instead?

static ConsoleLoggerFactory s_defaultLoggerFactory;

Then return &s_defaultLoggerFactory in getLoggerFactory().

[massakam]

@BewareMyPower
s_loggerFactory also has the same issue, right? s_loggerFactory used to be a static shared_ptr, but it seems that it was changed to its current type to avoid segfaults during process shutdown.
apache/pulsar#7132

[massakam]

Should I fix it like this?

static std::atomic<LoggerFactory*> s_defaultLoggerFactory(nullptr);

LoggerFactory* LogUtils::getLoggerFactory() {
    if (s_loggerFactory.load() != nullptr) {
        return s_loggerFactory.load();
    } else {
        if (s_defaultLoggerFactory.load() == nullptr) {
            LoggerFactory* oldFactory = nullptr;
            LoggerFactory* newFactory = new ConsoleLoggerFactory();
            if (!s_defaultLoggerFactory.compare_exchange_strong(oldFactory, newFactory)) {
                delete newFactory; // there's already a factory set
            }
        }
        return s_defaultLoggerFactory.load();
    }
}

[BewareMyPower]

Oh I see. I think currently it's okay. Your fix here is also good.

[BewareMyPower]

Then this patch LGTM no matter if this fix is applied.

[massakam]

Thank you for your confirmation. Then, I will not make the above modifications.