From 95aa713f78e7acf992abda2fbb7242a6d0cc753d Mon Sep 17 00:00:00 2001 From: Mr NeilBrown Date: Tue, 9 Feb 2021 11:28:45 +1100 Subject: [PATCH] LU-14428 libcfs: discard cfs_trace_console_buffers[] cfs_trace_console_buffers[] is a collection of buffers into which various messages are formatted - with vscnprintf or similar - and which are then passed to cfs_print_to_console which adds more formatted information. The two levels of formatting can instead be achieved using the "%pV" format which takes a format-and-args. If we do this, we don't need cfs_trace_console_buffers[] and more. One minor drawback is that cfs_tty_write_message() requires a final string to print, not a format plus arguments. This is only minor because there is precisely one message that is ever sent to cfs_tty_write_message(), and it contains no formatting. So we now generate a warning if the string passed with D_TTY ever contains formatting, and just print that string ignoring any formatting. Signed-off-by: Mr NeilBrown Change-Id: Ic78ac3703e5b6321dade8c367753c0aec1cae60b Reviewed-on: https://review.whamcloud.com/41489 Tested-by: jenkins Tested-by: Maloo Reviewed-by: James Simmons Reviewed-by: Aurelien Degremont Reviewed-by: Oleg Drokin --- libcfs/libcfs/tracefile.c | 144 ++++++++++++++++++++-------------------------- 1 file changed, 61 insertions(+), 83 deletions(-) diff --git a/libcfs/libcfs/tracefile.c b/libcfs/libcfs/tracefile.c index b32f458..93c1fb3 100644 --- a/libcfs/libcfs/tracefile.c +++ b/libcfs/libcfs/tracefile.c @@ -48,7 +48,6 @@ #include #include -#define CFS_TRACE_CONSOLE_BUFFER_SIZE 1024 enum cfs_trace_buf_type { CFS_TCD_TYPE_PROC = 0, @@ -59,7 +58,6 @@ enum cfs_trace_buf_type { union cfs_trace_data_union (*cfs_trace_data[CFS_TCD_TYPE_CNT])[NR_CPUS] __cacheline_aligned; -char *cfs_trace_console_buffers[NR_CPUS][CFS_TCD_TYPE_CNT]; char cfs_tracefile[TRACEFILE_NAME_SIZE]; long long cfs_tracefile_size = CFS_TRACEFILE_SIZE; static struct tracefiled_ctl trace_tctl; @@ -127,14 +125,6 @@ enum cfs_trace_buf_type cfs_trace_buf_idx_get(void) return CFS_TCD_TYPE_PROC; } -static inline char *cfs_trace_get_console_buffer(void) -{ - unsigned int i = get_cpu(); - unsigned int j = cfs_trace_buf_idx_get(); - - return cfs_trace_console_buffers[i][j]; -} - static inline struct cfs_trace_cpu_data * cfs_trace_get_tcd(void) { @@ -370,9 +360,9 @@ static void cfs_tty_write_message(const char *prefix, int mask, const char *msg) tty_kref_put(tty); } -static void cfs_print_to_console(struct ptldebug_header *hdr, int mask, - const char *buf, int len, const char *file, - const char *fn) +static void cfs_vprint_to_console(struct ptldebug_header *hdr, int mask, + struct va_format *vaf, const char *file, + const char *fn) { char *prefix = "Lustre"; @@ -381,32 +371,46 @@ static void cfs_print_to_console(struct ptldebug_header *hdr, int mask, if (mask & D_CONSOLE) { if (mask & D_EMERG) - pr_emerg("%sError: %.*s", prefix, len, buf); + pr_emerg("%sError: %pV", prefix, vaf); else if (mask & D_ERROR) - pr_err("%sError: %.*s", prefix, len, buf); + pr_err("%sError: %pV", prefix, vaf); else if (mask & D_WARNING) - pr_warn("%s: %.*s", prefix, len, buf); + pr_warn("%s: %pV", prefix, vaf); else if (mask & libcfs_printk) - pr_info("%s: %.*s", prefix, len, buf); + pr_info("%s: %pV", prefix, vaf); } else { if (mask & D_EMERG) - pr_emerg("%sError: %d:%d:(%s:%d:%s()) %.*s", prefix, + pr_emerg("%sError: %d:%d:(%s:%d:%s()) %pV", prefix, hdr->ph_pid, hdr->ph_extern_pid, file, - hdr->ph_line_num, fn, len, buf); + hdr->ph_line_num, fn, vaf); else if (mask & D_ERROR) - pr_err("%sError: %d:%d:(%s:%d:%s()) %.*s", prefix, + pr_err("%sError: %d:%d:(%s:%d:%s()) %pV", prefix, hdr->ph_pid, hdr->ph_extern_pid, file, - hdr->ph_line_num, fn, len, buf); + hdr->ph_line_num, fn, vaf); else if (mask & D_WARNING) - pr_warn("%s: %d:%d:(%s:%d:%s()) %.*s", prefix, + pr_warn("%s: %d:%d:(%s:%d:%s()) %pV", prefix, hdr->ph_pid, hdr->ph_extern_pid, file, - hdr->ph_line_num, fn, len, buf); + hdr->ph_line_num, fn, vaf); else if (mask & (D_CONSOLE | libcfs_printk)) - pr_info("%s: %.*s", prefix, len, buf); + pr_info("%s: %pV", prefix, vaf); } if (mask & D_TTY) - cfs_tty_write_message(prefix, mask, buf); + /* tty_write_msg doesn't handle formatting */ + cfs_tty_write_message(prefix, mask, vaf->fmt); +} + +static void cfs_print_to_console(struct ptldebug_header *hdr, int mask, + const char *file, const char *fn, + const char *fmt, ...) +{ + struct va_format vaf; + va_list args; + + va_start(args, fmt); + vaf.fmt = fmt; + vaf.va = &args; + cfs_vprint_to_console(hdr, mask, &vaf, file, fn); } int libcfs_debug_msg(struct libcfs_debug_msg_data *msgdata, @@ -509,6 +513,9 @@ int libcfs_debug_msg(struct libcfs_debug_msg_data *msgdata, if (needed < 2 || *(string_buf + needed - 2) != '\r') pr_info("Lustre: format at %s:%d:%s doesn't end in '\\r\\n'\n", file, msgdata->msg_line, msgdata->msg_fn); + if (strnchr(string_buf, needed, '%')) + pr_info("Lustre: format at %s:%d:%s mustn't contain %%\n", + file, msgdata->msg_line, msgdata->msg_fn); } header.ph_len = known_size + needed; @@ -573,36 +580,28 @@ console: } if (tcd) { - cfs_print_to_console(&header, mask, string_buf, needed, file, - msgdata->msg_fn); + cfs_print_to_console(&header, mask, file, msgdata->msg_fn, + "%s", string_buf); cfs_trace_put_tcd(tcd); } else { - string_buf = cfs_trace_get_console_buffer(); + struct va_format vaf; va_start(ap, format); - needed = vscnprintf(string_buf, CFS_TRACE_CONSOLE_BUFFER_SIZE, - format, ap); + vaf.fmt = format; + vaf.va = ≈ + cfs_vprint_to_console(&header, mask, + &vaf, file, msgdata->msg_fn); va_end(ap); - - cfs_print_to_console(&header, mask, - string_buf, needed, file, msgdata->msg_fn); - - put_cpu(); } if (cdls != NULL && cdls->cdls_count != 0) { - string_buf = cfs_trace_get_console_buffer(); - - needed = scnprintf(string_buf, CFS_TRACE_CONSOLE_BUFFER_SIZE, - "Skipped %d previous similar message%s\n", - cdls->cdls_count, - (cdls->cdls_count > 1) ? "s" : ""); - /* Do not allow print this to TTY */ - cfs_print_to_console(&header, mask & ~D_TTY, string_buf, - needed, file, msgdata->msg_fn); + cfs_print_to_console(&header, mask & ~D_TTY, file, + msgdata->msg_fn, + "Skipped %d previous similar message%s\n", + cdls->cdls_count, + (cdls->cdls_count > 1) ? "s" : ""); - put_cpu(); cdls->cdls_count = 0; } @@ -622,8 +621,8 @@ cfs_trace_assertion_failed(const char *str, cfs_set_ptldebug_header(&hdr, msgdata, CDEBUG_STACK()); - cfs_print_to_console(&hdr, D_EMERG, str, strlen(str), - msgdata->msg_file, msgdata->msg_fn); + cfs_print_to_console(&hdr, D_EMERG, msgdata->msg_file, msgdata->msg_fn, + "%s", str); panic("Lustre debug assertion failure\n"); @@ -778,20 +777,21 @@ void cfs_trace_debug_print(void) page = tage->page; p = page_address(page); while (p < ((char *)page_address(page) + tage->used)) { - struct ptldebug_header *hdr; - int len; - hdr = (void *)p; - p += sizeof(*hdr); - file = p; - p += strlen(file) + 1; - fn = p; - p += strlen(fn) + 1; - len = hdr->ph_len - (int)(p - (char *)hdr); - - cfs_print_to_console(hdr, D_EMERG, p, len, file, fn); - - p += len; - } + struct ptldebug_header *hdr; + int len; + hdr = (void *)p; + p += sizeof(*hdr); + file = p; + p += strlen(file) + 1; + fn = p; + p += strlen(fn) + 1; + len = hdr->ph_len - (int)(p - (char *)hdr); + + cfs_print_to_console(hdr, D_EMERG, file, fn, + "%.*s", len, p); + + p += len; + } list_del(&tage->linkage); cfs_tage_free(tage); @@ -1252,23 +1252,8 @@ int cfs_tracefile_init(int max_pages) tcd->tcd_shutting_down = 0; } - for (i = 0; i < num_possible_cpus(); i++) - for (j = 0; j < 3; j++) { - cfs_trace_console_buffers[i][j] = - kmalloc(CFS_TRACE_CONSOLE_BUFFER_SIZE, - GFP_KERNEL); - if (!cfs_trace_console_buffers[i][j]) - goto out_buffers; - } - return 0; -out_buffers: - for (i = 0; i < num_possible_cpus(); i++) - for (j = 0; j < 3; j++) { - kfree(cfs_trace_console_buffers[i][j]); - cfs_trace_console_buffers[i][j] = NULL; - } out_trace_data: for (i = 0; cfs_trace_data[i]; i++) { kfree(cfs_trace_data[i]); @@ -1309,18 +1294,11 @@ static void cfs_trace_cleanup(void) { struct page_collection pc; int i; - int j; INIT_LIST_HEAD(&pc.pc_pages); trace_cleanup_on_all_cpus(); - for (i = 0; i < num_possible_cpus(); i++) - for (j = 0; j < 3; j++) { - kfree(cfs_trace_console_buffers[i][j]); - cfs_trace_console_buffers[i][j] = NULL; - } - for (i = 0; i < CFS_TCD_TYPE_CNT && cfs_trace_data[i]; i++) { kfree(cfs_trace_data[i]); cfs_trace_data[i] = NULL; -- 1.8.3.1