Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Configuration option to output logs in logfmt #12934

Open
wants to merge 17 commits into
base: unstable
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
15 changes: 15 additions & 0 deletions src/config.c
Expand Up @@ -164,6 +164,19 @@ configEnum propagation_error_behavior_enum[] = {
{NULL, 0}
};

configEnum log_format_enum[] = {
{"default", LOG_FORMAT_DEFAULT},
{"logfmt", LOG_FORMAT_LOGFMT},
{NULL, 0}
};

configEnum log_timestamp_format_enum[] = {
{"default", LOG_TIMESTAMP_DEFAULT},
{"iso8601", LOG_TIMESTAMP_ISO8601},
{"unix",LOG_TIMESTAMP_UNIX},
{NULL, 0}
};

/* Output buffer limits presets. */
clientBufferLimitsConfig clientBufferLimitsDefaults[CLIENT_TYPE_OBUF_COUNT] = {
{0, 0, 0}, /* normal */
Expand Down Expand Up @@ -3154,6 +3167,8 @@ standardConfig static_configs[] = {
createEnumConfig("propagation-error-behavior", NULL, MODIFIABLE_CONFIG, propagation_error_behavior_enum, server.propagation_error_behavior, PROPAGATION_ERR_BEHAVIOR_IGNORE, NULL, NULL),
createEnumConfig("shutdown-on-sigint", NULL, MODIFIABLE_CONFIG | MULTI_ARG_CONFIG, shutdown_on_sig_enum, server.shutdown_on_sigint, 0, isValidShutdownOnSigFlags, NULL),
createEnumConfig("shutdown-on-sigterm", NULL, MODIFIABLE_CONFIG | MULTI_ARG_CONFIG, shutdown_on_sig_enum, server.shutdown_on_sigterm, 0, isValidShutdownOnSigFlags, NULL),
createEnumConfig("log-format", NULL, MODIFIABLE_CONFIG, log_format_enum, server.log_format, LOG_FORMAT_DEFAULT, NULL, NULL),
createEnumConfig("log-timestamp-format", NULL, MODIFIABLE_CONFIG, log_timestamp_format_enum, server.log_timestamp_format, LOG_TIMESTAMP_DEFAULT, NULL, NULL),

/* Integer configs */
createIntConfig("databases", NULL, IMMUTABLE_CONFIG, 1, INT_MAX, server.dbnum, 16, INTEGER_CONFIG, NULL, NULL),
Expand Down
69 changes: 61 additions & 8 deletions src/server.c
Expand Up @@ -108,11 +108,35 @@ const char *replstateToString(int replstate);
* function of Redis may be called from other threads. */
void nolocks_localtime(struct tm *tmp, time_t t, time_t tz, int dst);

/* Formats the timezone offset into a string.
*
* Assumes:
* - size of `buf` is 7 or larger
* - `timezone` is valid, within the range of [-50400, +43200].
* - `daylight_active` indicates whether dst is active (1) or not (0). */

void format_timezone(char *buf, int timezone, int daylight_active) {
// Adjust the timezone for daylight saving, if active
int total_offset = (-1)*timezone + 3600*daylight_active;
int hours = abs(total_offset / 3600);
int minutes = abs(total_offset % 3600) / 60;
buf[0] = total_offset >= 0 ? '+' : '-';
buf[1] = '0' + hours / 10;
buf[2] = '0' + hours % 10;
buf[3] = ':';
buf[4] = '0' + minutes / 10;
buf[5] = '0' + minutes % 10;
buf[6] = '\0';
}

/* Low level logging. To use only for very big messages, otherwise
* serverLog() is to prefer. */
void serverLogRaw(int level, const char *msg) {
const int syslogLevelMap[] = { LOG_DEBUG, LOG_INFO, LOG_NOTICE, LOG_WARNING };
const char *c = ".-*#";
const char* verbose_level[] = {"debug", "info", "notice", "warning"};
const char* roles[] = {"sentinel", "RDB/AOF", "replica", "master"};
const char* role_chars = "XCSM";
FILE *fp;
char buf[64];
int rawmode = (level & LL_RAW);
Expand All @@ -129,23 +153,52 @@ void serverLogRaw(int level, const char *msg) {
} else {
int off;
struct timeval tv;
int role_char;
pid_t pid = getpid();

gettimeofday(&tv,NULL);
struct tm tm;
nolocks_localtime(&tm,tv.tv_sec,server.timezone,server.daylight_active);
off = strftime(buf,sizeof(buf),"%d %b %Y %H:%M:%S.",&tm);
snprintf(buf+off,sizeof(buf)-off,"%03d",(int)tv.tv_usec/1000);
switch(server.log_timestamp_format) {
case LOG_TIMESTAMP_DEFAULT:
off = strftime(buf,sizeof(buf),"%d %b %Y %H:%M:%S.",&tm);
snprintf(buf+off,sizeof(buf)-off,"%03d",(int)tv.tv_usec/1000);
break;

case LOG_TIMESTAMP_ISO8601:
off = strftime(buf,sizeof(buf),"%Y-%m-%dT%H:%M:%S.",&tm);
char tzbuf[7];
format_timezone(tzbuf, server.timezone, server.daylight_active);
snprintf(buf + off, sizeof(buf) - off, "%03d%s",
(int)tv.tv_usec/1000, tzbuf);
break;

case LOG_TIMESTAMP_UNIX:
snprintf(buf,sizeof(buf),"%ld",tv.tv_sec);
break;
default:
break;
}
int role_index;
if (server.sentinel_mode) {
role_char = 'X'; /* Sentinel. */
role_index = 0; /* Sentinel. */
} else if (pid != server.pid) {
role_char = 'C'; /* RDB / AOF writing child. */
role_index = 1; /* RDB / AOF writing child. */
} else {
role_char = (server.masterhost ? 'S':'M'); /* Slave or Master. */
role_index = (server.masterhost ? 2 : 3); /* Slave or Master. */
}
switch (server.log_format) {
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There are 6 combinations of log_format X role. Could be more moving forward. This is another way to code the logic, but I'm not sure if it's the "better" way...
It does keep the minimum memory usage for role print though.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this approach is sensible enough.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We could do like we do for verbosity level. For the legacy format we pick a char from "XCSM" and for logfmt a string from an array, same index.

case LOG_FORMAT_LOGFMT: {
fprintf(fp, "pid=%d role=%s timestamp=\"%s\" level=%s message=\"%s\"\n",
(int)getpid(),roles[role_index],buf,verbose_level[level],msg);
break;
}

default: {
fprintf(fp,"%d:%c %s %c %s\n",
(int)getpid(),role_chars[role_index], buf,c[level],msg);
break;
}
}
fprintf(fp,"%d:%c %s %c %s\n",
(int)getpid(),role_char, buf,c[level],msg);
}
fflush(fp);

Expand Down
14 changes: 14 additions & 0 deletions src/server.h
Expand Up @@ -608,6 +608,18 @@ typedef enum {
#define PAUSE_ACTION_EVICT (1<<3)
#define PAUSE_ACTION_REPLICA (1<<4) /* pause replica traffic */

/* Sets log format */
typedef enum {
LOG_FORMAT_DEFAULT = 0,
LOG_FORMAT_LOGFMT
} log_format_type;

/* Sets log timestamp format */
/* Also update LOG_TIMESTAMP_FORMATS */
#define LOG_TIMESTAMP_DEFAULT 0
#define LOG_TIMESTAMP_ISO8601 1
#define LOG_TIMESTAMP_UNIX 2

/* common sets of actions to pause/unpause */
#define PAUSE_ACTIONS_CLIENT_WRITE_SET (PAUSE_ACTION_CLIENT_WRITE|\
PAUSE_ACTION_EXPIRE|\
Expand Down Expand Up @@ -1865,6 +1877,8 @@ struct redisServer {
int memcheck_enabled; /* Enable memory check on crash. */
int use_exit_on_panic; /* Use exit() on panic and assert rather than
* abort(). useful for Valgrind. */
int log_format; /* Print log in specific format */
int log_timestamp_format; /* Timestamp format in log */
/* Shutdown */
int shutdown_timeout; /* Graceful shutdown time limit in seconds. */
int shutdown_on_sigint; /* Shutdown flags configured for SIGINT. */
Expand Down