Revert "Introduce spdlog logging system"

[icculus]

This reverts commit b0e5754.

I'm not against a better logging system, but introducing an external dependency for it seems like a wrong move, especially since it adds a bunch of complexity to write text to stdout.

If we're dead-set on keeping spdlog, please close this PR and we can start a new one that removes the external dependency, using their header-only version instead included in this repo, so people don't need to track down the library from elsewhere.

But really, I don't think we should keep this at all.

(Also, SDL2 has a SDL_Log function which does the right thing even on platforms without stdout, if that was the reason for choosing spdlog, so in a future where the Windows builds also use SDL, that might be a viable solution, but I'm not specifically advocating for that with this PR.)

[bryanperris]

I am on board for whatever decision everyone ends up agreeing on.

[Jayman2000]

What was the motivation for using spdlog to begin with?

[bryanperris]

Improve spdlog integration #248

@Jayman2000 #248

[Jayman2000]

Improve spdlog integration #248

@Jayman2000 #248

OK. If I’m understanding that thread correctly, spdlog was added in order to make it easier to implement these three features:

• A command-line option that’s similar to journalctl’s --priority= option. In other words, a command-line option that makes Descent 3 print more or less messages depending on how severe the messages are.
• A command-line option to output logs to a file instead of (or perhaps in addition to) stdout/ stderr.
• Trace prints (I’m not sure what these are).

Did I get that right? I ask because reading #248 felt like reading inside baseball to me.

[bryanperris]

Improve spdlog integration #248

@Jayman2000 #248

OK. If I’m understanding that thread correctly, spdlog was added in order to make it easier to implement these three features:

• A command-line option that’s similar to journalctl’s --priority= option. In other words, a command-line option that makes Descent 3 print more or less messages depending on how severe the messages are.
• A command-line option to output logs to a file instead of (or perhaps in addition to) stdout/ stderr.
• Trace prints (I’m not sure what these are).

Did I get that right? I ask because reading #248 felt like reading inside baseball to me.

Command line flags is just one idea on how to control the logs, the log system is unaware of this stuff. It is very common today that software logs to a logger construct rather directly to a stream, and then backend loggers can be customized on what they do with the logging, like dump it to rotating log files or send it up a network server, etc. Don't forget formatting of the log messages can be used, even separately per logger backend (eg: colored text for terminals). It seems lately, people only think why bother with a logging framework on top standard output streams, but its there for collecting and organizing data. The Android OS provides a built in logging framework that allow logs to be sent to a server when an app bug is reported. When logging through spdlog's provided macros, they can capture the source file and line number, so know where exactly these log messages came from. No one has to guess anymore on what might be the problem is, at least we can log out better clues, at least for D3 builds running without the debugger, still the debugger only breaks when a breakpoint is hit or some signal is trapped, and still you do not get human friendly information from that. With logging, we could log out the details of how the mission file was loaded and setup.

Trace log level is for the nitty gritty stuff where you may dump large amount of data as a string, it is never recommended to use that in release bugs, trace logs are allowed to slow down the entire process for the sake of capturing a high volume amount detailed data when someone enables it explicitly at build time.

Here is a response from ChatGPT
`The main purpose of the trace log level in software development is to provide highly detailed information about the application's operation, primarily intended for diagnosing problems and understanding system behavior at a very granular level. This can include step-by-step tracing of events, method calls, and system states, which is especially useful during development and debugging processes.

Here’s why trace logging is often disabled at compile time in production environments:

Performance Impact: Trace logging can significantly affect the performance of an application. Because it captures detailed information about many aspects of the application, it can lead to large amounts of data being written to log files. This process consumes I/O resources and can slow down the application, especially if the logging is not optimized or the I/O subsystem is already under heavy load.
Security and Privacy Concerns: Trace logs can potentially include sensitive information such as user data, system configuration, and security settings. If these logs are exposed due to misconfiguration or security vulnerabilities, it could lead to data breaches or other security incidents.
Log Volume and Management: The volume of data generated by trace logging is typically very large, which can lead to challenges in log management. Storing, searching, and analyzing these logs can become problematic, requiring additional storage resources and sophisticated log management tools, which might not be feasible or cost-effective for every project.
Noise Over Signal: Trace logs can produce a lot of "noise" — detailed entries that are not useful in everyday operations. In a production environment, too much information can obscure important information, making it harder to detect and respond to real issues.
To mitigate these concerns, trace logging is often enabled conditionally using compile-time flags or runtime configuration settings. This allows developers to enable it when needed (e.g., during a specific testing phase or to troubleshoot a particular issue) without impacting the general performance and security of the application in production environments.`

[Jayman2000]

OK, so here’s a new list based on #248 and on the information that you just gave me. The motivation for having spdlog is to make it easier to implement these features:

• The ability to output logs + metadata to something like systemd-journald.
• The ability to output logs + metadata to a file.
• Something that’s similar to journalctl’s --priority= option. It might be a command-line option, it might be an option in a config file, or it might be a statement that says “import the logs into another piece of software and them filter them there.”
• Filenames and line numbers for every log message.
• A log level named trace. Specifically, the trace log level will be used to log tons of information related to level loading. It might also be used for other things.

Did I understand correctly?

[bryanperris]

OK, so here’s a new list based on #248 and on the information that you just gave me. The motivation for having spdlog is to make it easier to implement these features:

• The ability to output logs + metadata to something like systemd-journald.
• The ability to output logs + metadata to a file.
• Something that’s similar to journalctl’s --priority= option. It might be a command-line option, it might be an option in a config file, or it might be a statement that says “import the logs into another piece of software and them filter them there.”
• Filenames and line numbers for every log message.
• A log level named trace. Specifically, the trace log level will be used to log tons of information related to level loading. It might also be used for other things.

Did I understand correctly?

systemd journal is just for systemd services not standalone applications. Trace level in general just means a lot of detailed stuff can be logged, it could be used anywhere. I always use compile time flags to control the logging, but it seems other want to use a simple cli verbosity flag to control them as well. I think -logging is all we need, to simply turn on logging to file, which can be just info, error and warn.

[Jayman2000]

systemd journal is just for systemd services not standalone applications.

I think that you misunderstood what I was trying to say. I said “The ability to output logs + metadata to something like systemd-journald.” I wasn’t trying to say that anyone would output logs to any particular piece of software. I was just trying to use an example that I’m familiar in order to check whether or not I was understanding. Instead of saying “something like systemd-journald”, what would have been a better example for me to have used? Does that Android logging framework that you mentioned earlier have a name?

I always use compile time flags to control the logging, but it seems other want to use a simple cli verbosity flag to control them as well.

OK. What if I changed my previous statement to this:

• Something that’s similar to journalctl’s --priority= option. It might be a command-line option, it might be a compile-time option, it might be a combination of the previous two, or it might be something else entirely.

Would that be a more accurate reflection?

[bryanperris]

systemd journal is just for systemd services not standalone applications.

I think that you misunderstood what I was trying to say. I said “The ability to output logs + metadata to something like systemd-journald.” I wasn’t trying to say that anyone would output logs to any particular piece of software. I was just trying to use an example that I’m familiar in order to check whether or not I was understanding. Instead of saying “something like systemd-journald”, what would have been a better example for me to have used? Does that Android logging framework that you mentioned earlier have a name?

I always use compile time flags to control the logging, but it seems other want to use a simple cli verbosity flag to control them as well.

OK. What if I changed my previous statement to this:

• Something that’s similar to journalctl’s --priority= option. It might be a command-line option, it might be a compile-time option, it might be a combination of the previous two, or it might be something else entirely.

Would that be a more accurate reflection?

Gotcha.

Read about Log4j, https://logging.apache.org/log4j/2.x/, https://en.wikipedia.org/wiki/Log4j, this is what Android's logging is based on, since app development in general has been based on the Java language (in fact the apps can be compiled from Java). Log4j has always been the prime example, and has inspired many others. It has been around for 23 years.

--priority is similar to the log verbosity stuff for spdlog, if you were to control it via command line.

[Jayman2000]

I took the list of features that I had mentioned previously, and I tried to implement them myself in an example project. In the example project, I used SDL’s logging API. I did so to try and see if SDL’s logging API is suitable for our purposes. Here’s what I learned from trying to implement each of the features on my list:

• The ability to output logs + metadata to something like systemd-journald.

For my example implementation, I decided to actually libsystemd to make my application output logs to systemd-journald. I only did so because I’m familiar with systemd, not because it’s a particularly good choice for our purposes.

In order to get SDL’s logging API to send logs to systemd-journald, I had to write a custom SDL_LogOutputFunction. This would have been pretty easy, but this next feature made things complicated:

• Filenames and line numbers for every log message.

Unfortunately, SDL’s logging API and systemd’s logging API were kind of incompatible here. For SDL’s logging API, I had to write a function with this signature:

void CustomLogOutputFunction(void *userdata, int category,
                             SDL_LogPriority priority, const char *message);

The problem here is SDL_LogOutputFunctions don’t get told the filename or line number of the message that they’re outputting. I was able to overcome this problem by creating a macro. Instead of calling SDL_LogMessage() directly, I would call the macro which would pass the filename, line number, function name and the actual log message to SDL_LogMessage(). Then, I would have to call this function from libsystemd:

int sd_journal_print_with_location(int priority,
                                   const char *file,
                                   const char *line,
                                   const char *func,
                                   const char *format,
                                   ...);

By the time a messages gets passed to an SDL_LogOutputFunction, the filename and line number are embedded in its message parameter. As a result, I had to write code that would carefully extract each piece of information that was embedded in message and copy them into new strings so that they could be passed to sd_journal_print_with_location(). Honestly, this was probably more effort than it was worth. If I had to do it again, I would have just kept the filenames and line numbers embedded in the log message. The filename, line number and function name wouldn’t have been recorded in the way that systemd-journald expects them to be, but that’s OK.

• The ability to output logs + metadata to a file.

This was easy to implement. All I had to do was add a little bit of code to my custom SDL_LogOutputFunction.

• Something that’s similar to journalctl’s --priority= option. It might be a command-line option, it might be a compile-time option, it might be a combination of the previous two, or it might be something else entirely.

SDL’s logging API gives us this for free. Specifically, you can set the SDL_LOGGING environment variable to control which messages get filtered out.

• A log level named trace. Specifically, the trace log level will be used to log tons of information related to level loading. It might also be used for other things.

SDL calls this log level “verbose”. I haven’t tried it myself, but I think that you could create a preprocessor macro that calls SDL_LogVerbose in debug builds and does nothing in release builds.

---

In summary, it seems like we can use SDL’s logging API to implement everything that we want to implement with minimal effort. All we have to do is:

• Create a macro that calls SDL_LogMessage with filenames and line numbers embedded in the message.
• Create a custom SDL_LogOutputFunction that can output logs to a file or some sort of log capturing service.

The only thing that we can’t do easily is output logs to some sort of database that has fields specifically for filenames and line numbers. It is certainly possible to do that, it’s just not easy.

If we were to stick with spdlog, then we would still need to write a custom SDL_LogOutputFunction. We would need to write a custom SDL_LogOutputFunction that takes any messages generated by SDL itself and sends them to spdlog so that they end up in the same place as the rest of the logs.

---

My conclusion is that we should get rid of spdlog in favor of using SDL’s logging API. It seems wasteful to have two independent logging mechanisms for a single application. When you consider the fact that we’ll have to write a custom SDL_LogOutputFunction either way, my guess is that using SDL’s logging API is only going to take slightly more effort than using spdlog.

[Lgt2x]

Alright, this logging situation has dragged on for too long, it's starting to become ridiculous. There is so much other areas to improve D3 on, let's not waste anymore time on this issue. #341 replaces this PR and #327, removes the spdlog dependency while keeping the logging module if we want to improve on SDL2's.