[PATCH v2 0/6] Changes to trace-cmd logs

[PATCH v2 0/6] Changes to trace-cmd logs

[Tzvetomir Stoyanov (VMware)]

Recently changes in traceevent and tracefs libraries were introduced: log
levels and new APIs to modify them. As trace-cmd library uses traceevent
and tracefs libraries, those changes affect trace-cmd as well.

v2 changes:
 - Reverted back the weak definitions of log functions.
 - Fixed a typo in a variable name.

Tzvetomir Stoyanov (VMware) (6):
  trace-cmd library: Add log levels
  trace-cmd library: Document the API for log levels
  trace-cmd library: Renamed tracecmd_fatal() to tracecmd_critical()
  trace-cmd library: Set debug log level in debug mode
  trace-cmd report: Set the log level with -V and -q options
  trace-cmd: Add new function to set log level

 Documentation/libtracecmd/libtracecmd-log.txt | 78 +++++++++++++++++++
 Documentation/libtracecmd/libtracecmd.txt     |  3 +
 include/trace-cmd/trace-cmd.h                 |  2 +
 lib/trace-cmd/include/trace-cmd-local.h       |  2 +-
 lib/trace-cmd/trace-input.c                   | 12 +--
 lib/trace-cmd/trace-util.c                    | 34 ++++++--
 tracecmd/include/trace-local.h                |  2 +
 tracecmd/trace-cmd.c                          | 40 ++++++++++
 tracecmd/trace-read.c                         |  2 +
 9 files changed, 163 insertions(+), 12 deletions(-)
 create mode 100644 Documentation/libtracecmd/libtracecmd-log.txt

-- 
2.31.1

[PATCH v2 1/6] trace-cmd library: Add log levels

[Tzvetomir Stoyanov (VMware)]

Add levels to library logs and introduce a new API to set the desired
log severity:
 tracecmd_set_loglevel()
When a new trace-cmd library log level is set, propagate it to tracefs
and traceevent libraries as well.

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 include/trace-cmd/trace-cmd.h |  2 ++
 lib/trace-cmd/trace-util.c    | 24 ++++++++++++++++++++++--
 2 files changed, 24 insertions(+), 2 deletions(-)

diff --git a/include/trace-cmd/trace-cmd.h b/include/trace-cmd/trace-cmd.h
index 7305487c..6984db86 100644
--- a/include/trace-cmd/trace-cmd.h
+++ b/include/trace-cmd/trace-cmd.h
@@ -43,4 +43,6 @@ int tracecmd_buffer_instances(struct tracecmd_input *handle);
 const char *tracecmd_buffer_instance_name(struct tracecmd_input *handle, int indx);
 struct tracecmd_input *tracecmd_buffer_instance_handle(struct tracecmd_input *handle, int indx);
 
+void tracecmd_set_loglevel(enum tep_loglevel level);
+
 #endif /* _TRACE_CMD_H */
diff --git a/lib/trace-cmd/trace-util.c b/lib/trace-cmd/trace-util.c
index 049fe049..6db754e4 100644
--- a/lib/trace-cmd/trace-util.c
+++ b/lib/trace-cmd/trace-util.c
@@ -30,7 +30,7 @@
 #define PROC_STACK_FILE "/proc/sys/kernel/stack_tracer_enabled"
 
 static bool debug;
-
+static int log_level = TEP_LOG_CRITICAL;
 static FILE *logfp;
 
 const static struct {
@@ -355,19 +355,36 @@ trace_load_plugins(struct tep_handle *tep, int flags)
 	return list;
 }
 
+/**
+ * tracecmd_set_loglevel - set log level of the library
+ * @level: desired level of the library messages
+ */
+void tracecmd_set_loglevel(enum tep_loglevel level)
+{
+	log_level = level;
+	tracefs_set_loglevel(level);
+	tep_set_loglevel(level);
+}
+
 void __weak tracecmd_warning(const char *fmt, ...)
 {
 	va_list ap;
 
+	if (log_level < TEP_LOG_WARNING)
+		return;
+
 	va_start(ap, fmt);
 	tep_vprint("libtracecmd", TEP_LOG_WARNING, true, fmt, ap);
 	va_end(ap);
 }
 
-void tracecmd_info(const char *fmt, ...)
+void __weak tracecmd_info(const char *fmt, ...)
 {
 	va_list ap;
 
+	if (log_level < TEP_LOG_INFO)
+		return;
+
 	va_start(ap, fmt);
 	tep_vprint("libtracecmd", TEP_LOG_INFO, false, fmt, ap);
 	va_end(ap);
@@ -379,6 +396,9 @@ void __weak tracecmd_fatal(const char *fmt, ...)
 	int ret;
 	va_list ap;
 
+	if (log_level < TEP_LOG_CRITICAL)
+		return;
+
 	va_start(ap, fmt);
 	ret = tep_vprint("libtracecmd", TEP_LOG_CRITICAL, true, fmt, ap);
 	va_end(ap);
-- 
2.31.1

[PATCH v2 2/6] trace-cmd library: Document the API for log levels

[Tzvetomir Stoyanov (VMware)]

Updated trace-cmd library man pages with description of the API for
setting the library log levels:
 tracecmd_set_loglevel()

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 Documentation/libtracecmd/libtracecmd-log.txt | 78 +++++++++++++++++++
 Documentation/libtracecmd/libtracecmd.txt     |  3 +
 2 files changed, 81 insertions(+)
 create mode 100644 Documentation/libtracecmd/libtracecmd-log.txt

diff --git a/Documentation/libtracecmd/libtracecmd-log.txt b/Documentation/libtracecmd/libtracecmd-log.txt
new file mode 100644
index 00000000..de5c2776
--- /dev/null
+++ b/Documentation/libtracecmd/libtracecmd-log.txt
@@ -0,0 +1,78 @@
+libtracecmd(3)
+=============
+
+NAME
+----
+tracecmd_set_loglevel - Set log level of the library
+
+SYNOPSIS
+--------
+[verse]
+--
+*#include <trace-cmd.h>*
+
+int *tracecmd_set_loglevel*(enum tep_loglevel _level_);
+--
+
+DESCRIPTION
+-----------
+The _tracecmd_set_loglevel()_ function sets the level of the library logs that will be printed on
+the console. See _libtraceevent(3)_ for detailed desciription of the log levels. Setting the log
+level to specific value means that logs from the previous levels will be printed too. For example
+_TEP_LOG_WARNING_ will print any logs with severity _TEP_LOG_WARNING_, _TEP_LOG_ERROR_ and
+_TEP_LOG_CRITICAL_. The default log level is _TEP_LOG_CRITICAL_.  When a new level is set, it is
+also propagated to the libtracefs and libtraceevent.
+
+EXAMPLE
+-------
+[source,c]
+--
+#include <trace-cmd.h>
+...
+tracecmd_set_loglevel(TEP_LOG_ALL);
+...
+/* call libtracecmd, libtracefs or libtraceevent APIs and observe any logs they produce */
+...
+tracecmd_set_loglevel(TEP_LOG_CRITICAL);
+--
+
+FILES
+-----
+[verse]
+--
+*trace-cmd.h*
+	Header file to include in order to have access to the library APIs.
+*-ltracecmd*
+	Linker switch to add when building a program that uses the library.
+--
+
+SEE ALSO
+--------
+_libtracefs(3)_,
+_libtraceevent(3)_,
+_trace-cmd(1)_
+_trace-cmd.dat(5)_
+
+AUTHOR
+------
+[verse]
+--
+*Steven Rostedt* <rostedt@goodmis.org>
+*Tzvetomir Stoyanov* <tz.stoyanov@gmail.com>
+--
+REPORTING BUGS
+--------------
+Report bugs to  <linux-trace-devel@vger.kernel.org>
+
+LICENSE
+-------
+libtracecmd is Free Software licensed under the GNU LGPL 2.1
+
+RESOURCES
+---------
+https://git.kernel.org/pub/scm/utils/trace-cmd/trace-cmd.git/
+
+COPYING
+-------
+Copyright \(C) 2021 VMware, Inc. Free use of this software is granted under
+the terms of the GNU Public License (GPL).
diff --git a/Documentation/libtracecmd/libtracecmd.txt b/Documentation/libtracecmd/libtracecmd.txt
index adc9321c..dc528ce0 100644
--- a/Documentation/libtracecmd/libtracecmd.txt
+++ b/Documentation/libtracecmd/libtracecmd.txt
@@ -33,6 +33,9 @@ Read tracing instances from a trace file:
 Get traceing peer information from a trace file:
 	unsigned long long *tracecmd_get_traceid*(struct tracecmd_input pass:[*]_handle_);
 	int *tracecmd_get_guest_cpumap*(struct tracecmd_input pass:[*]_handle_, unsigned long long _trace_id_, const char pass:[*]pass:[*]_name_, int pass:[*]_vcpu_count_, const int pass:[*]pass:[*]_cpu_pid_);
+
+Control library logs:
+	int *tracecmd_set_loglevel*(enum tep_loglevel _level_);
 --
 
 DESCRIPTION
-- 
2.31.1

[PATCH v2 3/6] trace-cmd library: Renamed tracecmd_fatal() to tracecmd_critical()

[Tzvetomir Stoyanov (VMware)]

The trace-cmd library function for pritning critical logs is renamed
from tracecmd_fatal() to tracecmd_critical() to be consistent with the
names of the log levels.

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 lib/trace-cmd/include/trace-cmd-local.h |  2 +-
 lib/trace-cmd/trace-input.c             | 12 ++++++------
 lib/trace-cmd/trace-util.c              |  5 ++---
 3 files changed, 9 insertions(+), 10 deletions(-)

diff --git a/lib/trace-cmd/include/trace-cmd-local.h b/lib/trace-cmd/include/trace-cmd-local.h
index cd868f60..821b5cdb 100644
--- a/lib/trace-cmd/include/trace-cmd-local.h
+++ b/lib/trace-cmd/include/trace-cmd-local.h
@@ -11,7 +11,7 @@
 
 /* Can be overridden */
 void tracecmd_warning(const char *fmt, ...);
-void tracecmd_fatal(const char *fmt, ...);
+void tracecmd_critical(const char *fmt, ...);
 void tracecmd_info(const char *fmt, ...);
 
 /* trace.dat file format version */
diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c
index 2e519752..5ee69b14 100644
--- a/lib/trace-cmd/trace-input.c
+++ b/lib/trace-cmd/trace-input.c
@@ -1105,7 +1105,7 @@ static void __free_page(struct tracecmd_input *handle, struct page *page)
 	int index;
 
 	if (!page->ref_count) {
-		tracecmd_fatal("Page ref count is zero!\n");
+		tracecmd_critical("Page ref count is zero!\n");
 		return;
 	}
 
@@ -1166,7 +1166,7 @@ void tracecmd_free_record(struct tep_record *record)
 		return;
 
 	if (!record->ref_count) {
-		tracecmd_fatal("record ref count is zero!");
+		tracecmd_critical("record ref count is zero!");
 		return;
 	}
 
@@ -1176,7 +1176,7 @@ void tracecmd_free_record(struct tep_record *record)
 		return;
 
 	if (record->locked) {
-		tracecmd_fatal("freeing record when it is locked!");
+		tracecmd_critical("freeing record when it is locked!");
 		return;
 	}
 
@@ -1375,7 +1375,7 @@ static int get_page(struct tracecmd_input *handle, int cpu,
 
 	if (offset & (handle->page_size - 1)) {
 		errno = -EINVAL;
-		tracecmd_fatal("bad page offset %llx", offset);
+		tracecmd_critical("bad page offset %llx", offset);
 		return -1;
 	}
 
@@ -1383,7 +1383,7 @@ static int get_page(struct tracecmd_input *handle, int cpu,
 	    offset > handle->cpu_data[cpu].file_offset +
 	    handle->cpu_data[cpu].file_size) {
 		errno = -EINVAL;
-		tracecmd_fatal("bad page offset %llx", offset);
+		tracecmd_critical("bad page offset %llx", offset);
 		return -1;
 	}
 
@@ -1949,7 +1949,7 @@ tracecmd_peek_data(struct tracecmd_input *handle, int cpu)
 
 		record = handle->cpu_data[cpu].next;
 		if (!record->data) {
-			tracecmd_fatal("Something freed the record");
+			tracecmd_critical("Something freed the record");
 			return NULL;
 		}
 
diff --git a/lib/trace-cmd/trace-util.c b/lib/trace-cmd/trace-util.c
index 6db754e4..be9fcf0e 100644
--- a/lib/trace-cmd/trace-util.c
+++ b/lib/trace-cmd/trace-util.c
@@ -390,8 +390,7 @@ void __weak tracecmd_info(const char *fmt, ...)
 	va_end(ap);
 }
 
-
-void __weak tracecmd_fatal(const char *fmt, ...)
+void __weak tracecmd_critical(const char *fmt, ...)
 {
 	int ret;
 	va_list ap;
@@ -560,7 +559,7 @@ int tracecmd_count_cpus(void)
 
 	fp = fopen("/proc/cpuinfo", "r");
 	if (!fp) {
-		tracecmd_fatal("Can not read cpuinfo");
+		tracecmd_critical("Can not read cpuinfo");
 		return 0;
 	}
 
-- 
2.31.1

[PATCH v2 4/6] trace-cmd library: Set debug log level in debug mode

[Tzvetomir Stoyanov (VMware)]

When the library works in debug mode, set the log level to debug.

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 lib/trace-cmd/trace-util.c | 5 +++++
 1 file changed, 5 insertions(+)

diff --git a/lib/trace-cmd/trace-util.c b/lib/trace-cmd/trace-util.c
index be9fcf0e..b65f9dec 100644
--- a/lib/trace-cmd/trace-util.c
+++ b/lib/trace-cmd/trace-util.c
@@ -93,6 +93,11 @@ const char *tracecmd_clock_id2str(enum tracecmd_clocks clock)
 void tracecmd_set_debug(bool set_debug)
 {
 	debug = set_debug;
+
+	if (set_debug)
+		tracecmd_set_loglevel(TEP_LOG_DEBUG);
+	else
+		tracecmd_set_loglevel(TEP_LOG_CRITICAL);
 }
 
 /**
-- 
2.31.1

[PATCH v2 5/6] trace-cmd report: Set the log level with -V and -q options

[Tzvetomir Stoyanov (VMware)]

When "trace-cmd report -V" is specified, set the log level to INFO.
When "trace-cmd report -q" is specified, set the log level to NONE.

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 tracecmd/trace-read.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/tracecmd/trace-read.c b/tracecmd/trace-read.c
index b315283e..0cf6e773 100644
--- a/tracecmd/trace-read.c
+++ b/tracecmd/trace-read.c
@@ -1703,9 +1703,11 @@ void trace_report (int argc, char **argv)
 			break;
 		case 'V':
 			show_status = 1;
+			tracecmd_set_loglevel(TEP_LOG_INFO);
 			break;
 		case 'q':
 			silence_warnings = 1;
+			tracecmd_set_loglevel(TEP_LOG_NONE);
 			break;
 		case OPT_cpu:
 			parse_cpulist(optarg);
-- 
2.31.1

[PATCH v2 6/6] trace-cmd: Add new function to set log level

[Tzvetomir Stoyanov (VMware)]

Introduce a new trace-cmd internal function to set the application log
level.
 trace_set_verbose()
The log level can be set using string with log id or log name.

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 tracecmd/include/trace-local.h |  2 ++
 tracecmd/trace-cmd.c           | 40 ++++++++++++++++++++++++++++++++++
 2 files changed, 42 insertions(+)

diff --git a/tracecmd/include/trace-local.h b/tracecmd/include/trace-local.h
index 4c5669c9..e9a0aea8 100644
--- a/tracecmd/include/trace-local.h
+++ b/tracecmd/include/trace-local.h
@@ -39,6 +39,8 @@ void usage(char **argv);
 extern int silence_warnings;
 extern int show_status;
 
+int trace_set_verbose(char *level);
+
 struct pid_record_data {
 	int			pid;
 	int			brass[2];
diff --git a/tracecmd/trace-cmd.c b/tracecmd/trace-cmd.c
index 60cd3ea1..00cdaa37 100644
--- a/tracecmd/trace-cmd.c
+++ b/tracecmd/trace-cmd.c
@@ -45,6 +45,46 @@ void *malloc_or_die(unsigned int size)
 	return data;
 }
 
+static struct trace_log_severity {
+	int		id;
+	const char	*name;
+} log_severity[] = {
+	{ .id = TEP_LOG_NONE, .name = "none" },
+	{ .id = TEP_LOG_CRITICAL, .name = "crit" },
+	{ .id = TEP_LOG_ERROR, .name = "err" },
+	{ .id = TEP_LOG_WARNING, .name = "warn" },
+	{ .id = TEP_LOG_INFO, .name = "info" },
+	{ .id = TEP_LOG_DEBUG, .name = "debug" },
+	{ .id = TEP_LOG_ALL, .name = "all" },
+};
+
+int trace_set_verbose(char *level)
+{
+	int id;
+
+	if (!level)
+		return -1;
+
+	if (isdigit(level[0])) {
+		id = atoi(level);
+		if (id >= TEP_LOG_NONE && id <= TEP_LOG_ALL) {
+			tracecmd_set_loglevel(id);
+			return 0;
+		}
+	} else {
+		int size = ARRAY_SIZE(log_severity);
+		int i;
+
+		for (i = 0; i < size; i++) {
+			if (!strncmp(level, log_severity[i].name, strlen(log_severity[i].name))) {
+				tracecmd_set_loglevel(log_severity[i].id);
+				return 0;
+			}
+		}
+	}
+
+	return -1;
+}
 
 /**
  * struct command
-- 
2.31.1