Making an X-Plane plugin “talk” to us is one of the boilerplate tasks when setting up a new plugin project. X-Plane has its own log file, log.txt, which is found in X-Plane’s root folder. The file gets reset every time X-Plane starts, so there’s no need to rotate or trim it from time to time. As a plugin author, we have the choice to either write our own log file, or to jump on X-Plane’s bandwagon and use its logging system for our purposes. While I can see the benefits of having a dedicated logfile for a plugin, personally I prefer to use X-Plane’s built in logging mechanism – there are technical reasons, but mostly it’s a comfort and usability decision: most X-Plane users will immediately think of the central log.txt file when a developer asks them to provide their log file (e.g. when reporting an issue).
So let’s take a look at the XPLMUtilities API provided by the X-Plane SDK. It provides a function called XPLMDebugString, which provides a pretty simple interface to X-Plane’s logging mechanism:
1#include <XPLMUtilities.h>
2
3XPLM_API void XPLMDebugString(const char *message);
What this function does is pretty straight forward - it appends the string message to the log.txt log file. It doesn’t add fancy timestamps, it doesn’t care for log levels and verbosity, and it doesn’t process format strings and arguments. In consequence, if we need all that (and normally we do), we’ll have to implement it ourselves.
For this purpose, let’s create two files called log.h and log.c within our plugin’s source code directory (if you followed my earlier post on this subject, the source files would go into the src directory). Let’s start with the log API we’d like to have available in the other modules of our plugin. I prefer to have a set of four logging functions, so let’s define them in log.h:
1#ifndef _DAEMOPLUG_LOG_H_
2#define _DAEMOPLUG_LOG_H_
3
4#ifdef __cplusplus
5extern "C" {
6#endif
7
8#include <stdarg.h>
9
10#define LOG_BUFFER_SIZE 256
11
12typedef enum log_level
13{
14 Debug=0,
15 Info=1,
16 Warn=2,
17 Error=4
18} log_level_t;
19
20void log_debug(const char *, ...);
21void log_info(const char *, ...);
22void log_warn(const char *, ...);
23void log_error(const char *, ...);
24
25#ifdef __cplusplus
26}
27#endif
28
29#endif /* _DAEMOPLUG_LOG_H_ */
These function prototypes all expect a string, followed by arbitrary arguments. Basically the same syntax you’d use with the printf() family of functions. Now, following the DRY (“don’t repeat yourself”) principle, it doesn’t make sense to implement the full logging functionality four times. Instead, we’re going to implement a single logging function, which will do the log processing on behalf of the logging API functions. The function as I implemented it in log.c looks like this:
1#include <stdarg.h>
2#include <stdio.h>
3#include <string.h>
4
5#include <XPLMDataAccess.h>
6#include <XPLMUtilities.h>
7
8#include "log.h"
9
10
11log_level_t MinLogLevel = Debug;
12
13
14const char *log_level_string(log_level_t level)
15{
16 switch (level)
17 {
18 case Debug:
19 return "DEBUG";
20 break;
21
22 case Info:
23 return " INFO";
24 break;
25
26 case Warn:
27 return " WARN";
28 break;
29
30 case Error:
31 return "ERROR";
32 break;
33
34 default:
35 return "INVAL";
36 break;
37 }
38}
39
40
41void log_msg_v(log_level_t level, const char *message, va_list args)
42{
43 /* don't log anything below the set log level */
44 if (level < MinLogLevel)
45 {
46 return;
47 }
48
49 /* retrieve data for the time stamp (X-Plane convention) */
50 int hrs, min;
51 float sec, net_time = XPLMGetDataf(XPLMFindDataRef("sim/network/misc/network_time_sec"));
52 hrs = (int)(net_time / 3600.0f);
53 min = (int)(net_time / 60.0f) - (int)(hrs * 60.0f);
54 sec = net_time - (hrs * 3600.0f) - (min * 60.0f);
55
56 /* create the message by rolling in eventual arguments */
57 char msg_buffer[LOG_BUFFER_SIZE + 1];
58 memset(msg_buffer, '\0', LOG_BUFFER_SIZE + 1);
59 vsnprintf(msg_buffer, LOG_BUFFER_SIZE, message, args);
60
61 /* prepare the log buffer and send it to log.txt */
62 char log_buffer[LOG_BUFFER_SIZE + 64];
63 memset(log_buffer, '\0', LOG_BUFFER_SIZE + 64);
64 snprintf(log_buffer, LOG_BUFFER_SIZE + 64, "%d:%02d:%06.3f [DAEMOPLUG]: %s: %s\n", hrs, min, sec, log_level_string(level), msg_buffer);
65 XPLMDebugString(log_buffer);
66}
I created a global variable MinLogLevel instead of defining it as a constant in log.h for a simple reason — this way I can modify the log level at runtime, e.g. through a configuration file when initializing the plugin or similar. One of the rare cases where a global variable makes sense, given you only ever write to it in a dedicated place (e.g. define a function log_level_set() and make it publicly available).
log_level_string() is only an auxiliary function, providing a 6 bytes long string containing the log level label (5 characters plus string terminator). The actual work is done in log_msg_v() (I append _v to functions which require a va_list argument, but we’ll get to that in a moment). In a first step, we check if the log level of the message submitted is actually high enough to go through — otherwise we can already stop here. As already mentioned, we have to take care of providing our own time stamp if we want one (useful to see the timing of certain events in the log, so I highly recommend it). Using X-Plane’s sim/network/misc/network_time_sec data ref as time source keeps our timestamps in sync with those used by X-Plane internally. Calculating hours, minutes and seconds is just a bit of simple maths.
The third step is to actually assemble the message. So far the message consists of a format string (message in our example), and eventual further parameters stored in the args parameter (strictly speaking args is just a pointer to the data structure holding those parameters, ). stdio.h provides a variant of the s(n)printf function, taking a single va_list pointer instead of individual arguments after the format string. Wherever possible, I try using the n versions of these functions to have a solid protection from buffer overflows and subsequent segmentation faults.
Finally all information can be merged into the complete message — time stamp, plugin identifier, log level and the message we just assembled, and the completed buffer gets handed over to X-Plane’s XPLMDebugString() function, which takes care that the message actually gets written into the log.txt log file, even in case of a crash (at least if the crash occurs after XPLMDebugString() has been called).
What remains now is the public interface — as an example, I’m going to show here just the log_debug() function. The other three look almost identical:
1void log_debug(const char *message, ...)
2{
3 va_list args;
4
5 va_start(args, message);
6 log_msg_v(Debug, message, args);
7 va_end(args);
8}
As usual, there are many more possibilities to solve the logging problem in X-Plane. However, I feel it’s crucial to have the most simple and straight-forward interface available, so the principle of format strings and arbitrary arguments is one I would never give up — having to start fiddling with buffers the moment I just want to log an error doesn’t seem appealing to me. Anything else IMO is a matter of taste, including the exact format of the log string.