BUG/MINOR: log: make "show startup-log" use a ring buffer instead
The copy of the startup logs used to rely on a re-allocated memory area
on the fly, that would attempt to be delivered at once over the CLI. But
if it's too large (too many warnings) it will take time to start up, and
may not even show up on the CLI as it doesn't fit in a buffer.
The ring buffer infrastructure solves all this with no more code, let's
switch to this instead. It simply requires a parsing function to attach
the ring via ring_attach_cli() and all the rest is automatically handled.
Initially this was imagined as a code cleanup, until a test with a config
involving 100k backends and just one occurrence of
"load-server-state-from-file global" in the defaults section took approx
20 minutes to parse due to the O(N^2) cost of concatenating the warnings
resulting in ~1 TB of data to be copied, while it took only 0.57s with
the ring.
Ideally this patch should be backported to 2.0 and 1.9, though it relies
on the ring infrastructure which will then also need to be backported.
Configs able to trigger the bug are uncommon, so another workaround for
older versions without backporting the rings would consist in simply
limiting the size of the error message in print_message() to something
always printable, which will only return the first errors.
diff --git a/src/log.c b/src/log.c
index ae4121d..c4e0082 100644
--- a/src/log.c
+++ b/src/log.c
@@ -248,7 +248,7 @@
/* A global buffer used to store all startup alerts/warnings. It will then be
* retrieve on the CLI. */
-static char *startup_logs = NULL;
+static struct ring *startup_logs = NULL;
struct logformat_var_args {
char *name;
@@ -1056,8 +1056,21 @@
label, tm.tm_yday, tm.tm_hour, tm.tm_min, tm.tm_sec, (int)getpid());
memvprintf(&msg, fmt, argp);
- if (global.mode & MODE_STARTING)
- memprintf(&startup_logs, "%s%s%s", (startup_logs ? startup_logs : ""), head, msg);
+ if (global.mode & MODE_STARTING) {
+ if (unlikely(!startup_logs))
+ startup_logs = ring_new(STARTUP_LOG_SIZE);
+
+ if (likely(startup_logs)) {
+ struct ist m[2];
+
+ m[0] = ist(head);
+ m[1] = ist(msg);
+ /* trim the trailing '\n' */
+ if (m[1].len > 0 && m[1].ptr[m[1].len - 1] == '\n')
+ m[1].len--;
+ ring_write(startup_logs, ~0, 0, 0, m, 2);
+ }
+ }
fprintf(stderr, "%s%s", head, msg);
fflush(stderr);
@@ -1901,20 +1914,15 @@
/* Deinitialize log buffers used for syslog messages */
void deinit_log_buffers()
{
- void *tmp_startup_logs;
-
free(logheader);
free(logheader_rfc5424);
free(logline);
free(logline_rfc5424);
- tmp_startup_logs = _HA_ATOMIC_XCHG(&startup_logs, NULL);
- free(tmp_startup_logs);
-
+ ring_free(_HA_ATOMIC_XCHG(&startup_logs, NULL));
logheader = NULL;
logheader_rfc5424 = NULL;
logline = NULL;
logline_rfc5424 = NULL;
- startup_logs = NULL;
}
/* Builds a log line in <dst> based on <list_format>, and stops before reaching
@@ -3027,23 +3035,22 @@
__send_log(logsrvs, tag, level, logline, data_len, default_rfc5424_sd_log_format, 2);
}
-static int cli_io_handler_show_startup_logs(struct appctx *appctx)
+/* parse the "show startup-logs" command, returns 1 if a message is returned, otherwise zero */
+static int cli_parse_show_startup_logs(char **args, char *payload, struct appctx *appctx, void *private)
{
- struct stream_interface *si = appctx->owner;
- const char *msg = (startup_logs ? startup_logs : "No startup alerts/warnings.\n");
+ if (!cli_has_level(appctx, ACCESS_LVL_OPER))
+ return 1;
- if (ci_putstr(si_ic(si), msg) == -1) {
- si_rx_room_blk(si);
- return 0;
- }
- return 1;
+ if (!startup_logs)
+ return cli_msg(appctx, LOG_INFO, "\n"); // nothing to print
+
+ return ring_attach_cli(startup_logs, appctx);
}
/* register cli keywords */
static struct cli_kw_list cli_kws = {{ },{
{ { "show", "startup-logs", NULL },
- "show startup-logs : report logs emitted during HAProxy startup",
- NULL, cli_io_handler_show_startup_logs },
+ "show startup-logs : report logs emitted during HAProxy startup", cli_parse_show_startup_logs, NULL, NULL },
{{},}
}};