Applcation crash

[tuxroger]

Good afternoon,
I have been using spdlog for a while and I have faced many weird situations but this one is blowing my mind. I do not know what can be happenning.

This is the code snippet:

// Session Logging functions
bool PBConnectionThread::createSessionLogger(const std::string& loggerName, const std::string& filename)
{
SPDLOG_LOGGER_INFO(logger, "");
SPDLOG_LOGGER_INFO(logger, "Creating session log with filename '{}'.", filename);

std::vector<spdlog::sink_ptr> sinks;

auto rotating = std::make_shared<spdlog::sinks::rotating_file_sink_mt>(filename, 1024 * 1024 * 50, 5, true);	// 50 MB
if (rotating == nullptr)
{
	SPDLOG_LOGGER_ERROR(logger, "Error while creating rotating_file_sink_mt file sink");
	return false;	// early exit
}
sinks.push_back(rotating);

sessionLogger = std::make_shared<spdlog::logger>(loggerName, begin(sinks), end(sinks));
if (sessionLogger == nullptr)
{
	SPDLOG_LOGGER_ERROR(logger, "Error while creating spdlog logger");
	return false; // early exit
}
sessionLogger->set_level(spdlog::level::trace);

spdlog::register_logger(sessionLogger);
SPDLOG_LOGGER_INFO(logger, "Succesfully created connection logger!", filename);

return true;

}

This code, from time to time is making my application crash. Here is an example of the output when it is crashing:

[2023-03-29 09:49:02.012] [ProbeBuilderServer] [info] PBConnectionThread::createSessionLogsDirectory[t3147436335914322354]
[2023-03-29 09:49:02.012] [ProbeBuilderServer] [info] PBConnectionThread::createSessionLog[t3147436335914322354]
[2023-03-29 09:49:02.012] [ProbeBuilderServer] [info] PBConnectionThread::createConnectionLogger[t3147436335914322354]
[2023-03-29 09:49:02.013] [ProbeBuilderServer] [info] PBConnectionThread::createConnectionLogger[t3147436335914322354]: Creating session log with filename 'LOGS/log_Richardson_{b0d2be45-b578-4bf5-a260-0f13125a54eb}_29Mar2023094902AM.log'.

ORA-24550: signal received: Unhandled exception: Code=e06d7363 Flags=1

As you can see something happens between the beginning of the function and the end of it. As you can also see, I am checking for all the possible nullptrs along the function code.

As I mentioned above, this crash occurs from time to time and I do not why.

Thanks for your time!

[tt4g]

The e06d7363 code represents a system error.
It may be a system problem and a crash dump should be investigated.

See: debugging - Decoding the parameters of a thrown C++ exception (0xE06D7363) - Stack Overflow

In most cases, it is a lack of permissions to access folders or files, or a lack of memory.

[tt4g]

ORA-24550: signal received: Unhandled exception: Code=e06d7363 Flags=1

ORA-24550 is an Oracle database error code.
I thought spdlog was not the cause of the crash?

[tuxroger]

You are right, this error is always shown but I am not really performing any operation in the database backend while this is failing. That's why I thought this exception is thrown as a result of the application crashing and oracle throws an error while freeing up resources.

[tuxroger]

Hello, I just got a crash dump of the application. Here is a screenshot in which you can see that dropping the logger raises an exception:

Do you have any idea what can be raising the exception?
Thanks!

[tt4g]

The loggerName variable is an invalid reference.

Or logger_map_mutex_ is broken because the PGConnectionThread destructor is called after the application exits.
This is probably caused by not calling spdlog::shutdown() before the application exit.

spdlog/include/spdlog/details/registry-inl.h

Lines 219 to 227 in 0ca574a

	SPDLOG_INLINE void registry::drop(const std::string &logger_name)
	{
	std::lock_guard<std::mutex> lock(logger_map_mutex_);
	loggers_.erase(logger_name);
	if (default_logger_ && default_logger_->name() == logger_name)
	{
	default_logger_.reset();
	}
	}

[tuxroger]

loggerName is actually this:

dropSessionLogger(sessionLogger->name());

and sessionLogger is std::shared_ptrspdlog::logger sessionLogger; and it is not null since it would crash in some other way.

How can the name of a logger be an invalid reference?

I am calling shutdown at the end of the application just before exiting but this specific case was a crash and that's why you don't see the call in the stack.

[tt4g]

If the PGConnectionThread destructor is being called after the application exit, then logger_map_mutex_ may be broken.
There is no guarantee that std::mutex will work after main() function.

[tuxroger]

The PBConnectionThread dtor is not being called after main(). I have a pool of threads and this is one of them being destroyed but I have more threads in the pool which are alive.
I mean, this crash did not happen when shutting down the application, it crashes while running.
Quick question, is there any problem that the loggerName is something like this? "{edf71852-9b22-4ddc-88b7-dee185cc2687}". I understand it is not a problem since it is a string but...
Thanks for your support!
Roger

[gabime]

Just a guess but perhaps try to replace dropSessionLogger(sessionLogger->name());
with dropSessionLogger(std::string(sessionLogger->name()));
Could be that the logger_name get destroyed in drop() and then used again in the if (default_logger_ && default_logger_->name() == logger_name

[tuxroger]

Ok thanks, I will try that.
This crash happens from time to time so it might be the case that from time to time (race condition) the logger gets destroyed before.
I have also a variable containing the logger name. I will try to use that string instead of the logger itself.
Thanks for your help!

[gabime]

@tuxroger Let us know if this fix this. Because if yes, spdlog's drop could be improved to avoid such cases.

[tuxroger]

Hello,
I already call drop without calling logger->name(). As this error only happens from time to time, I will assume that after certain time without failing the issue might be resolved. I will let you know the outcome.
Thanks again for your support!

[tuxroger]

Hi there,
I just wanted to let you know that my application is crashing now when creating the session logger.
Please find attached the stack trace of the error.
Thanks in advance for your time!

[tuxroger]

Thanks a lot! that makes a lot of sense, you don't want exceptions while logging. Thanks a lot! I will try to modify my code so when construction loggers I try/catch the block.
Thanks!

[tuxroger]

Good afternoon.
The application has crashed twice and I have the what() message for every exception that has been catched:

rotating_file_sink: failed renaming C:\Users\probebuilder\AppData\Local\PBServer\LOGS\log_Richardson_28Apr2023154849PM.log to C:\Users\probebuilder\AppData\Local\PBServer\LOGS\log_Richardson_28Apr2023154849PM.1.log: permission denied

rotating_file_sink: failed renaming C:\Users\probebuilder\AppData\Local\PBServer\LOGS\log_Richardson_28Apr2023160059PM.log to C:\Users\probebuilder\AppData\Local\PBServer\LOGS\log_Richardson_28Apr2023160059PM.1.log: permission denied

It looks like when changing the current .log file to the next one with the .1 suffix, there are problems with the permission / ownership of the current file (.log).

This has never happened to me

Thanks for your time!

[tuxroger]

By the way, according to the documentation only in the construction and destruction exceptions might be thrown but what happens if you try to log in a logger that is null?

SPDLOG_LOGGER_INFO(logger, "blahblah");

It simply does not log? Or a previous check should be performed so I dont access nullptr?

Thanks!

[tt4g]

The "permission denied" is a security problem and is not something spdlog has any control over.
Please make sure that you manage the machine's permissions yourselves.

The nullptr check should be done by you.

[tuxroger]

Thanks for the answer!
It is weird that the process has not privileges since it is the same proces that created the .log file and when it is full it is unable to rename it to .1.log
Do you have an idea how can this happen? I understand that if the file is in use by another process we could not rename it but the only one with the file open is the process that just created the file...
I will also try to investigate on my own and let you know.