aboutsummaryrefslogtreecommitdiffstats
path: root/src/lua/lua_logger.c
diff options
context:
space:
mode:
Diffstat (limited to 'src/lua/lua_logger.c')
-rw-r--r--src/lua/lua_logger.c569
1 files changed, 241 insertions, 328 deletions
diff --git a/src/lua/lua_logger.c b/src/lua/lua_logger.c
index 21aad8136..04ff81b6d 100644
--- a/src/lua/lua_logger.c
+++ b/src/lua/lua_logger.c
@@ -1,5 +1,5 @@
/*
- * Copyright 2024 Vsevolod Stakhov
+ * Copyright 2025 Vsevolod Stakhov
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
@@ -174,6 +174,11 @@ static const struct luaL_reg loggerlib_f[] = {
{"__tostring", rspamd_lua_class_tostring},
{NULL, NULL}};
+static gsize
+lua_logger_out_type(lua_State *L, int pos, char *outbuf,
+ gsize len, struct lua_logger_trace *trace,
+ enum lua_logger_escape_type esc_type);
+
static void
lua_common_log_line(GLogLevelFlags level,
lua_State *L,
@@ -203,23 +208,19 @@ lua_common_log_line(GLogLevelFlags level,
d.currentline);
}
- rspamd_common_log_function(NULL,
- level,
- module,
- uid,
- func_buf,
- "%s",
- msg);
+ p = func_buf;
}
else {
- rspamd_common_log_function(NULL,
- level,
- module,
- uid,
- G_STRFUNC,
- "%s",
- msg);
+ p = (char *) G_STRFUNC;
}
+
+ rspamd_common_log_function(NULL,
+ level,
+ module,
+ uid,
+ p,
+ "%s",
+ msg);
}
/*** Logger interface ***/
@@ -279,105 +280,161 @@ lua_logger_char_safe(int t, unsigned int esc_type)
return true;
}
-static gsize
-lua_logger_out_str(lua_State *L, int pos,
- char *outbuf, gsize len,
- struct lua_logger_trace *trace,
- enum lua_logger_escape_type esc_type)
+#define LUA_MAX_ARGS 32
+/* Gracefully handles argument mismatches by substituting missing args and noting extra args */
+static glong
+lua_logger_log_format_str(lua_State *L, int offset, char *logbuf, gsize remain,
+ const char *fmt,
+ enum lua_logger_escape_type esc_type)
{
- gsize slen, flen;
- const char *str = lua_tolstring(L, pos, &slen);
- static const char hexdigests[16] = "0123456789abcdef";
- gsize r = 0, s;
-
- if (str) {
- gboolean normal = TRUE;
- flen = MIN(slen, len - 1);
+ const char *c;
+ gsize r;
+ int digit;
+ char *d = logbuf;
+ unsigned int arg_num, cur_arg = 0, arg_max = lua_gettop(L) - offset;
+ gboolean args_used[LUA_MAX_ARGS];
+ unsigned int used_args_count = 0;
+
+ memset(args_used, 0, sizeof(args_used));
+ while (remain > 1 && *fmt) {
+ if (*fmt == '%') {
+ ++fmt;
+ c = fmt;
+ if (*fmt == 's') {
+ ++fmt;
+ ++cur_arg;
+ }
+ else {
+ arg_num = 0;
+ while ((digit = g_ascii_digit_value(*fmt)) >= 0) {
+ ++fmt;
+ arg_num = arg_num * 10 + digit;
+ if (arg_num >= LUA_MAX_ARGS) {
+ /* Avoid ridiculously large numbers */
+ fmt = c;
+ break;
+ }
+ }
- for (r = 0; r < flen; r++) {
- if (!lua_logger_char_safe(str[r], esc_type)) {
- normal = FALSE;
- break;
+ if (fmt > c) {
+ /* Update the current argument */
+ cur_arg = arg_num;
+ }
}
- }
- if (normal) {
- r = rspamd_strlcpy(outbuf, str, flen + 1);
- }
- else {
- /* Need to escape non-printed characters */
- r = 0;
- s = 0;
-
- while (slen > 0 && len > 1) {
- if (!lua_logger_char_safe(str[s], esc_type)) {
- if (len >= 3) {
- outbuf[r++] = '\\';
- outbuf[r++] = hexdigests[((str[s] >> 4) & 0xF)];
- outbuf[r++] = hexdigests[((str[s]) & 0xF)];
-
- len -= 2;
- }
- else {
- outbuf[r++] = '?';
- }
+ if (fmt > c) {
+ if (cur_arg < 1 || cur_arg > arg_max) {
+ /* Missing argument - substitute placeholder */
+ r = rspamd_snprintf(d, remain, "<MISSING ARGUMENT>");
}
else {
- outbuf[r++] = str[s];
+ /* Valid argument - output it */
+ r = lua_logger_out(L, offset + cur_arg, d, remain, esc_type);
+ /* Track which arguments are used */
+ if (cur_arg <= LUA_MAX_ARGS && !args_used[cur_arg - 1]) {
+ args_used[cur_arg - 1] = TRUE;
+ used_args_count++;
+ }
}
- s++;
- slen--;
- len--;
+ g_assert(r < remain);
+ remain -= r;
+ d += r;
+ continue;
}
- outbuf[r] = '\0';
+ /* Copy % */
+ --fmt;
}
+
+ *d++ = *fmt++;
+ --remain;
}
- return r;
+ /* Check for extra arguments and append warning if any */
+ if (used_args_count > 0 && used_args_count < arg_max && remain > 1) {
+ unsigned int extra_args = arg_max - used_args_count;
+ r = rspamd_snprintf(d, remain, " <EXTRA %d ARGUMENTS>", (int) extra_args);
+ remain -= r;
+ d += r;
+ }
+
+ *d = 0;
+
+ return d - logbuf;
}
+#undef LUA_MAX_ARGS
+
static gsize
-lua_logger_out_num(lua_State *L, int pos, char *outbuf, gsize len,
- struct lua_logger_trace *trace)
+lua_logger_out_str(lua_State *L, int pos,
+ char *outbuf, gsize len,
+ enum lua_logger_escape_type esc_type)
{
- double num = lua_tonumber(L, pos);
- glong inum;
- gsize r = 0;
+ static const char hexdigests[16] = "0123456789abcdef";
+ gsize slen;
+ const unsigned char *str = lua_tolstring(L, pos, &slen);
+ unsigned char c;
+ char *out = outbuf;
- if ((double) (glong) num == num) {
- inum = num;
- r = rspamd_snprintf(outbuf, len + 1, "%l", inum);
+ if (str) {
+ while (slen > 0 && len > 1) {
+ c = *str++;
+ if (lua_logger_char_safe(c, esc_type)) {
+ *out++ = c;
+ }
+ else if (len > 3) {
+ /* Need to escape non-printed characters */
+ *out++ = '\\';
+ *out++ = hexdigests[c >> 4];
+ *out++ = hexdigests[c & 0xF];
+ len -= 2;
+ }
+ else {
+ *out++ = '?';
+ }
+ --slen;
+ --len;
+ }
}
- else {
- r = rspamd_snprintf(outbuf, len + 1, "%f", num);
+ *out = 0;
+
+ return out - outbuf;
+}
+
+static gsize
+lua_logger_out_num(lua_State *L, int pos, char *outbuf, gsize len)
+{
+ double num = lua_tonumber(L, pos);
+ glong inum = (glong) num;
+
+ if ((double) inum == num) {
+ return rspamd_snprintf(outbuf, len, "%l", inum);
}
- return r;
+ return rspamd_snprintf(outbuf, len, "%f", num);
}
static gsize
-lua_logger_out_boolean(lua_State *L, int pos, char *outbuf, gsize len,
- struct lua_logger_trace *trace)
+lua_logger_out_boolean(lua_State *L, int pos, char *outbuf, gsize len)
{
gboolean val = lua_toboolean(L, pos);
- gsize r = 0;
-
- r = rspamd_strlcpy(outbuf, val ? "true" : "false", len + 1);
- return r;
+ return rspamd_snprintf(outbuf, len, val ? "true" : "false");
}
static gsize
-lua_logger_out_userdata(lua_State *L, int pos, char *outbuf, gsize len,
- struct lua_logger_trace *trace)
+lua_logger_out_userdata(lua_State *L, int pos, char *outbuf, gsize len)
{
- int r = 0, top;
+ gsize r = 0;
+ int top;
const char *str = NULL;
gboolean converted_to_str = FALSE;
top = lua_gettop(L);
+ if (pos < 0) {
+ pos += top + 1; /* Convert to absolute */
+ }
if (!lua_getmetatable(L, pos)) {
return 0;
@@ -396,26 +453,17 @@ lua_logger_out_userdata(lua_State *L, int pos, char *outbuf, gsize len,
if (lua_isfunction(L, -1)) {
lua_pushvalue(L, pos);
- if (lua_pcall(L, 1, 1, 0) != 0) {
- lua_settop(L, top);
-
- return 0;
- }
-
- str = lua_tostring(L, -1);
-
- if (str) {
- r = rspamd_snprintf(outbuf, len, "%s", str);
+ if (lua_pcall(L, 1, 1, 0) == 0) {
+ str = lua_tostring(L, -1);
+ if (str) {
+ r = rspamd_snprintf(outbuf, len, "%s", str);
+ }
}
-
- lua_settop(L, top);
-
- return r;
}
}
lua_settop(L, top);
- return 0;
+ return r;
}
lua_pushstring(L, "__tostring");
@@ -460,12 +508,12 @@ lua_logger_out_userdata(lua_State *L, int pos, char *outbuf, gsize len,
return r;
}
-#define MOVE_BUF(d, remain, r) \
- (d) += (r); \
- (remain) -= (r); \
- if ((remain) == 0) { \
- lua_settop(L, old_top); \
- break; \
+#define MOVE_BUF(d, remain, r) \
+ (d) += (r); \
+ (remain) -= (r); \
+ if ((remain) <= 1) { \
+ lua_settop(L, top); \
+ goto table_oob; \
}
static gsize
@@ -473,169 +521,153 @@ lua_logger_out_table(lua_State *L, int pos, char *outbuf, gsize len,
struct lua_logger_trace *trace,
enum lua_logger_escape_type esc_type)
{
- char *d = outbuf;
- gsize remain = len, r;
+ char *d = outbuf, *str;
+ gsize remain = len;
+ glong r;
gboolean first = TRUE;
gconstpointer self = NULL;
- int i, tpos, last_seq = -1, old_top;
+ int i, last_seq = 0, top;
+ double num;
+ glong inum;
- if (!lua_istable(L, pos) || remain == 0) {
- return 0;
- }
+ /* Type and length checks are done in logger_out_type() */
- old_top = lua_gettop(L);
self = lua_topointer(L, pos);
/* Check if we have seen this pointer */
for (i = 0; i < TRACE_POINTS; i++) {
if (trace->traces[i] == self) {
- r = rspamd_snprintf(d, remain + 1, "ref(%p)", self);
-
- d += r;
-
- return (d - outbuf);
+ if ((trace->cur_level + TRACE_POINTS - 1) % TRACE_POINTS == i) {
+ return rspamd_snprintf(d, remain, "__self");
+ }
+ return rspamd_snprintf(d, remain, "ref(%p)", self);
}
}
trace->traces[trace->cur_level % TRACE_POINTS] = self;
+ ++trace->cur_level;
- lua_pushvalue(L, pos);
- r = rspamd_snprintf(d, remain + 1, "{");
- remain -= r;
- d += r;
+ top = lua_gettop(L);
+ if (pos < 0) {
+ pos += top + 1; /* Convert to absolute */
+ }
+
+ r = rspamd_snprintf(d, remain, "{");
+ MOVE_BUF(d, remain, r);
/* Get numeric keys (ipairs) */
for (i = 1;; i++) {
- lua_rawgeti(L, -1, i);
+ lua_rawgeti(L, pos, i);
if (lua_isnil(L, -1)) {
lua_pop(L, 1);
+ last_seq = i;
break;
}
- last_seq = i;
-
- if (!first) {
- r = rspamd_snprintf(d, remain + 1, ", ");
- MOVE_BUF(d, remain, r);
- }
-
- r = rspamd_snprintf(d, remain + 1, "[%d] = ", i);
- MOVE_BUF(d, remain, r);
- tpos = lua_gettop(L);
-
- if (lua_topointer(L, tpos) == self) {
- r = rspamd_snprintf(d, remain + 1, "__self");
+ if (first) {
+ first = FALSE;
+ str = "[%d] = ";
}
else {
- r = lua_logger_out_type(L, tpos, d, remain, trace, esc_type);
+ str = ", [%d] = ";
}
+ r = rspamd_snprintf(d, remain, str, i);
+ MOVE_BUF(d, remain, r);
+
+ r = lua_logger_out_type(L, -1, d, remain, trace, esc_type);
MOVE_BUF(d, remain, r);
- first = FALSE;
lua_pop(L, 1);
}
/* Get string keys (pairs) */
- for (lua_pushnil(L); lua_next(L, -2); lua_pop(L, 1)) {
+ for (lua_pushnil(L); lua_next(L, pos); lua_pop(L, 1)) {
/* 'key' is at index -2 and 'value' is at index -1 */
- if (lua_type(L, -2) == LUA_TNUMBER) {
- if (last_seq > 0) {
- lua_pushvalue(L, -2);
- if (lua_tonumber(L, -1) <= last_seq + 1) {
- lua_pop(L, 1);
+ /* Preserve key */
+ lua_pushvalue(L, -2);
+ if (last_seq > 0) {
+ if (lua_type(L, -1) == LUA_TNUMBER) {
+ num = lua_tonumber(L, -1); /* no conversion here */
+ inum = (glong) num;
+ if ((double) inum == num && inum > 0 && inum < last_seq) {
/* Already seen */
+ lua_pop(L, 1);
continue;
}
-
- lua_pop(L, 1);
}
}
- if (!first) {
- r = rspamd_snprintf(d, remain + 1, ", ");
- MOVE_BUF(d, remain, r);
- }
-
- /* Preserve key */
- lua_pushvalue(L, -2);
- r = rspamd_snprintf(d, remain + 1, "[%s] = ",
- lua_tostring(L, -1));
- lua_pop(L, 1); /* Remove key */
- MOVE_BUF(d, remain, r);
- tpos = lua_gettop(L);
-
- if (lua_topointer(L, tpos) == self) {
- r = rspamd_snprintf(d, remain + 1, "__self");
+ if (first) {
+ first = FALSE;
+ str = "[%2] = %1";
}
else {
- r = lua_logger_out_type(L, tpos, d, remain, trace, esc_type);
+ str = ", [%2] = %1";
}
+ r = lua_logger_log_format_str(L, top + 1, d, remain, str, esc_type);
+ /* lua_logger_log_format_str now handles errors gracefully */
MOVE_BUF(d, remain, r);
- first = FALSE;
+ /* Remove key */
+ lua_pop(L, 1);
}
- lua_settop(L, old_top);
-
- r = rspamd_snprintf(d, remain + 1, "}");
+ r = rspamd_snprintf(d, remain, "}");
d += r;
+table_oob:
+ --trace->cur_level;
+
return (d - outbuf);
}
#undef MOVE_BUF
-gsize lua_logger_out_type(lua_State *L, int pos,
- char *outbuf, gsize len,
- struct lua_logger_trace *trace,
- enum lua_logger_escape_type esc_type)
+static gsize
+lua_logger_out_type(lua_State *L, int pos,
+ char *outbuf, gsize len,
+ struct lua_logger_trace *trace,
+ enum lua_logger_escape_type esc_type)
{
- int type;
- gsize r = 0;
-
if (len == 0) {
return 0;
}
- type = lua_type(L, pos);
- trace->cur_level++;
+ int type = lua_type(L, pos);
switch (type) {
case LUA_TNUMBER:
- r = lua_logger_out_num(L, pos, outbuf, len, trace);
- break;
+ return lua_logger_out_num(L, pos, outbuf, len);
case LUA_TBOOLEAN:
- r = lua_logger_out_boolean(L, pos, outbuf, len, trace);
- break;
+ return lua_logger_out_boolean(L, pos, outbuf, len);
case LUA_TTABLE:
- r = lua_logger_out_table(L, pos, outbuf, len, trace, esc_type);
- break;
+ return lua_logger_out_table(L, pos, outbuf, len, trace, esc_type);
case LUA_TUSERDATA:
- r = lua_logger_out_userdata(L, pos, outbuf, len, trace);
- break;
+ return lua_logger_out_userdata(L, pos, outbuf, len);
case LUA_TFUNCTION:
- r = rspamd_snprintf(outbuf, len + 1, "function");
- break;
+ return rspamd_snprintf(outbuf, len, "function");
case LUA_TLIGHTUSERDATA:
- r = rspamd_snprintf(outbuf, len + 1, "0x%p", lua_topointer(L, pos));
- break;
+ return rspamd_snprintf(outbuf, len, "0x%p", lua_topointer(L, pos));
case LUA_TNIL:
- r = rspamd_snprintf(outbuf, len + 1, "nil");
- break;
+ return rspamd_snprintf(outbuf, len, "nil");
case LUA_TNONE:
- r = rspamd_snprintf(outbuf, len + 1, "no value");
- break;
- default:
- /* Try to push everything as string using tostring magic */
- r = lua_logger_out_str(L, pos, outbuf, len, trace, esc_type);
- break;
+ return rspamd_snprintf(outbuf, len, "no value");
}
- trace->cur_level--;
+ /* Try to push everything as string using tostring magic */
+ return lua_logger_out_str(L, pos, outbuf, len, esc_type);
+}
- return r;
+gsize lua_logger_out(lua_State *L, int pos,
+ char *outbuf, gsize len,
+ enum lua_logger_escape_type esc_type)
+{
+ struct lua_logger_trace tr;
+ memset(&tr, 0, sizeof(tr));
+
+ return lua_logger_out_type(L, pos, outbuf, len, &tr, esc_type);
}
static const char *
@@ -731,126 +763,13 @@ static gboolean
lua_logger_log_format(lua_State *L, int fmt_pos, gboolean is_string,
char *logbuf, gsize remain)
{
- char *d;
- const char *s, *c;
- gsize r, cpylen = 0;
- unsigned int arg_num = 0, cur_arg;
- bool num_arg = false;
- struct lua_logger_trace tr;
- enum {
- copy_char = 0,
- got_percent,
- parse_arg_num
- } state = copy_char;
-
- d = logbuf;
- s = lua_tostring(L, fmt_pos);
- c = s;
- cur_arg = fmt_pos;
-
- if (s == NULL) {
+ const char *fmt = lua_tostring(L, fmt_pos);
+ if (fmt == NULL) {
return FALSE;
}
- while (remain > 0 && *s != '\0') {
- switch (state) {
- case copy_char:
- if (*s == '%') {
- state = got_percent;
- s++;
- if (cpylen > 0) {
- memcpy(d, c, cpylen);
- d += cpylen;
- }
- cpylen = 0;
- }
- else {
- s++;
- cpylen++;
- remain--;
- }
- break;
- case got_percent:
- if (g_ascii_isdigit(*s) || *s == 's') {
- state = parse_arg_num;
- c = s;
- }
- else {
- *d++ = *s++;
- c = s;
- state = copy_char;
- }
- break;
- case parse_arg_num:
- if (g_ascii_isdigit(*s)) {
- s++;
- num_arg = true;
- }
- else {
- if (num_arg) {
- arg_num = strtoul(c, NULL, 10);
- arg_num += fmt_pos - 1;
- /* Update the current argument */
- cur_arg = arg_num;
- }
- else {
- /* We have non numeric argument, e.g. %s */
- arg_num = cur_arg++;
- s++;
- }
-
- if (arg_num < 1 || arg_num > (unsigned int) lua_gettop(L) + 1) {
- msg_err("wrong argument number: %ud", arg_num);
-
- return FALSE;
- }
-
- memset(&tr, 0, sizeof(tr));
- r = lua_logger_out_type(L, arg_num + 1, d, remain, &tr,
- is_string ? LUA_ESCAPE_UNPRINTABLE : LUA_ESCAPE_LOG);
- g_assert(r <= remain);
- remain -= r;
- d += r;
- state = copy_char;
- c = s;
- }
- break;
- }
- }
-
- if (state == parse_arg_num) {
- if (num_arg) {
- arg_num = strtoul(c, NULL, 10);
- arg_num += fmt_pos - 1;
- }
- else {
- /* We have non numeric argument, e.g. %s */
- arg_num = cur_arg;
- }
-
- if (arg_num < 1 || arg_num > (unsigned int) lua_gettop(L) + 1) {
- msg_err("wrong argument number: %ud", arg_num);
-
- return FALSE;
- }
-
- memset(&tr, 0, sizeof(tr));
- r = lua_logger_out_type(L, arg_num + 1, d, remain, &tr,
- is_string ? LUA_ESCAPE_UNPRINTABLE : LUA_ESCAPE_LOG);
- g_assert(r <= remain);
- remain -= r;
- d += r;
- }
- else if (state == copy_char) {
- if (cpylen > 0 && remain > 0) {
- memcpy(d, c, cpylen);
- d += cpylen;
- }
- }
-
- *d = '\0';
-
-
+ /* lua_logger_log_format_str now handles argument mismatches gracefully */
+ lua_logger_log_format_str(L, fmt_pos, logbuf, remain, fmt, is_string ? LUA_ESCAPE_UNPRINTABLE : LUA_ESCAPE_LOG);
return TRUE;
}
@@ -862,15 +781,10 @@ lua_logger_do_log(lua_State *L,
{
char logbuf[RSPAMD_LOGBUF_SIZE - 128];
const char *uid = NULL;
- int fmt_pos = start_pos;
int ret;
- GError *err = NULL;
- if (lua_type(L, start_pos) == LUA_TSTRING) {
- fmt_pos = start_pos;
- }
- else if (lua_type(L, start_pos) == LUA_TUSERDATA) {
- fmt_pos = start_pos + 1;
+ if (lua_type(L, start_pos) == LUA_TUSERDATA) {
+ GError *err = NULL;
uid = lua_logger_get_id(L, start_pos, &err);
@@ -884,15 +798,17 @@ lua_logger_do_log(lua_State *L,
return ret;
}
+
+ ++start_pos;
}
- else {
+
+ if (lua_type(L, start_pos) != LUA_TSTRING) {
/* Bad argument type */
return luaL_error(L, "bad format string type: %s",
lua_typename(L, lua_type(L, start_pos)));
}
- ret = lua_logger_log_format(L, fmt_pos, is_string,
- logbuf, sizeof(logbuf) - 1);
+ ret = lua_logger_log_format(L, start_pos, is_string, logbuf, sizeof(logbuf));
if (ret) {
if (is_string) {
@@ -903,12 +819,9 @@ lua_logger_do_log(lua_State *L,
lua_common_log_line(level, L, logbuf, uid, "lua", 1);
}
}
- else {
- if (is_string) {
- lua_pushnil(L);
-
- return 1;
- }
+ else if (is_string) {
+ lua_pushnil(L);
+ return 1;
}
return 0;
@@ -971,11 +884,11 @@ lua_logger_logx(lua_State *L)
if (uid && modname) {
if (lua_type(L, 4) == LUA_TSTRING) {
- ret = lua_logger_log_format(L, 4, FALSE, logbuf, sizeof(logbuf) - 1);
+ ret = lua_logger_log_format(L, 4, FALSE, logbuf, sizeof(logbuf));
}
else if (lua_type(L, 4) == LUA_TNUMBER) {
stack_pos = lua_tonumber(L, 4);
- ret = lua_logger_log_format(L, 5, FALSE, logbuf, sizeof(logbuf) - 1);
+ ret = lua_logger_log_format(L, 5, FALSE, logbuf, sizeof(logbuf));
}
else {
return luaL_error(L, "invalid argument on pos 4");
@@ -1013,11 +926,11 @@ lua_logger_debugm(lua_State *L)
if (uid && module) {
if (lua_type(L, 3) == LUA_TSTRING) {
- ret = lua_logger_log_format(L, 3, FALSE, logbuf, sizeof(logbuf) - 1);
+ ret = lua_logger_log_format(L, 3, FALSE, logbuf, sizeof(logbuf));
}
else if (lua_type(L, 3) == LUA_TNUMBER) {
stack_pos = lua_tonumber(L, 3);
- ret = lua_logger_log_format(L, 4, FALSE, logbuf, sizeof(logbuf) - 1);
+ ret = lua_logger_log_format(L, 4, FALSE, logbuf, sizeof(logbuf));
}
else {
return luaL_error(L, "invalid argument on pos 3");
generated by cgit v1.2.3 (git 2.39.1) at 2025-08-10 05:51:03 +0000