[PATCH v2 0/4] Add severity to library logs

[PATCH v2 0/4] Add severity to library logs

[Tzvetomir Stoyanov (VMware)]

Defined library log levels and add a new API to set the desired log level.

v2 changes:
 - Add a parameter to tep_vprint() for errno printing, insted of using the log
   level.

Tzvetomir Stoyanov (VMware) (4):
  libtraceevent: Add log levels
  libtraceevent: Add logs with severity info
  libtraceevent: Rename tep_vwarning() to tep_vprint()
  libtraceevent: Document new log functionality

 Documentation/libtraceevent-log.txt | 90 +++++++++++++++++++++++++++++
 Documentation/libtraceevent.txt     |  3 +
 src/event-parse.c                   | 14 ++---
 src/event-parse.h                   | 12 ++++
 src/event-plugin.c                  |  2 +-
 src/event-utils.h                   | 12 ++--
 src/parse-utils.c                   | 65 +++++++++++++--------
 7 files changed, 158 insertions(+), 40 deletions(-)
 create mode 100644 Documentation/libtraceevent-log.txt

-- 
2.31.1

[PATCH v2 1/4] libtraceevent: Add log levels

[Tzvetomir Stoyanov (VMware)]

Defined levels of the library logs and new API to set the desired log
level. By default, only critical logs are enabled.

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 src/event-parse.h | 12 ++++++++++++
 src/parse-utils.c | 16 ++++++++++++++++
 2 files changed, 28 insertions(+)

diff --git a/src/event-parse.h b/src/event-parse.h
index 05b156b..77be2b9 100644
--- a/src/event-parse.h
+++ b/src/event-parse.h
@@ -749,4 +749,16 @@ int tep_filter_copy(struct tep_event_filter *dest, struct tep_event_filter *sour
 
 int tep_filter_compare(struct tep_event_filter *filter1, struct tep_event_filter *filter2);
 
+/* Control library logs */
+enum tep_loglevel {
+	TEP_LOG_NONE = 0,
+	TEP_LOG_CRITICAL,
+	TEP_LOG_ERROR,
+	TEP_LOG_WARNING,
+	TEP_LOG_INFO,
+	TEP_LOG_DEBUG,
+	TEP_LOG_ALL
+};
+void tep_set_loglevel(enum tep_loglevel level);
+
 #endif /* _PARSE_EVENTS_H */
diff --git a/src/parse-utils.c b/src/parse-utils.c
index 6a4a2cd..bc89c44 100644
--- a/src/parse-utils.c
+++ b/src/parse-utils.c
@@ -9,8 +9,21 @@
 #include <stdarg.h>
 #include <errno.h>
 
+#include "event-parse.h"
+
 #define __weak __attribute__((weak))
 
+static int log_level = TEP_LOG_CRITICAL;
+
+/**
+ * tep_set_loglevel - set log level of the library
+ * @level: desired level of the library messages
+ */
+void tep_set_loglevel(enum tep_loglevel level)
+{
+	log_level = level;
+}
+
 int __weak tep_vwarning(const char *name, const char *fmt, va_list ap)
 {
 	int ret = errno;
@@ -29,6 +42,9 @@ void __weak tep_warning(const char *fmt, ...)
 {
 	va_list ap;
 
+	if (log_level < TEP_LOG_WARNING)
+		return;
+
 	va_start(ap, fmt);
 	tep_vwarning("libtraceevent", fmt, ap);
 	va_end(ap);
-- 
2.31.1

[PATCH v2 2/4] libtraceevent: Add logs with severity info

[Tzvetomir Stoyanov (VMware)]

Renamed existing pr_stat() internal function to tep_info() and limit it
to print only when the log level is TEP_LOG_INFO. Removed duplicated and
unused functions:
 vpr_stat()
 __pr_stat()
 __vpr_stat()

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 src/event-parse.c  | 14 +++++++-------
 src/event-plugin.c |  2 +-
 src/event-utils.h  |  7 +------
 src/parse-utils.c  | 24 ++++--------------------
 4 files changed, 13 insertions(+), 34 deletions(-)

diff --git a/src/event-parse.c b/src/event-parse.c
index 88ec909..97c1a97 100644
--- a/src/event-parse.c
+++ b/src/event-parse.c
@@ -6927,8 +6927,8 @@ static int find_event_handle(struct tep_handle *tep, struct tep_event *event)
 	if (!(*next))
 		return 0;
 
-	pr_stat("overriding event (%d) %s:%s with new print handler",
-		event->id, event->system, event->name);
+	tep_info("overriding event (%d) %s:%s with new print handler",
+		 event->id, event->system, event->name);
 
 	event->handler = handle->func;
 	event->context = handle->context;
@@ -7404,7 +7404,7 @@ int tep_register_print_function(struct tep_handle *tep,
 		 * plugins updating the function. This overrides the
 		 * system defaults.
 		 */
-		pr_stat("override of function helper '%s'", name);
+		tep_info("override of function helper '%s'", name);
 		remove_func_handler(tep, name);
 	}
 
@@ -7542,8 +7542,8 @@ int tep_register_event_handler(struct tep_handle *tep, int id,
 	if (event == NULL)
 		goto not_found;
 
-	pr_stat("overriding event (%d) %s:%s with new print handler",
-		event->id, event->system, event->name);
+	tep_info("overriding event (%d) %s:%s with new print handler",
+		 event->id, event->system, event->name);
 
 	event->handler = func;
 	event->context = context;
@@ -7628,8 +7628,8 @@ int tep_unregister_event_handler(struct tep_handle *tep, int id,
 		goto not_found;
 
 	if (event->handler == func && event->context == context) {
-		pr_stat("removing override handler for event (%d) %s:%s. Going back to default handler.",
-			event->id, event->system, event->name);
+		tep_info("removing override handler for event (%d) %s:%s. Going back to default handler.",
+			 event->id, event->system, event->name);
 
 		event->handler = NULL;
 		event->context = NULL;
diff --git a/src/event-plugin.c b/src/event-plugin.c
index df4a0a3..f42243f 100644
--- a/src/event-plugin.c
+++ b/src/event-plugin.c
@@ -497,7 +497,7 @@ load_plugin(struct tep_handle *tep, const char *path,
 	list->name = plugin;
 	*plugin_list = list;
 
-	pr_stat("registering plugin: %s", plugin);
+	tep_info("registering plugin: %s", plugin);
 	func(tep);
 	return;
 
diff --git a/src/event-utils.h b/src/event-utils.h
index ff4d6c4..1951557 100644
--- a/src/event-utils.h
+++ b/src/event-utils.h
@@ -9,15 +9,10 @@
 #include <ctype.h>
 #include <stdarg.h>
 
+void tep_info(const char *fmt, ...);
 /* Can be overridden */
 void tep_warning(const char *fmt, ...);
 int tep_vwarning(const char *name, const char *fmt, va_list ap);
-void pr_stat(const char *fmt, ...);
-void vpr_stat(const char *fmt, va_list ap);
-
-/* Always available */
-void __pr_stat(const char *fmt, ...);
-void __vpr_stat(const char *fmt, ...);
 
 #define min(x, y) ({				\
 	typeof(x) _min1 = (x);			\
diff --git a/src/parse-utils.c b/src/parse-utils.c
index bc89c44..b997823 100644
--- a/src/parse-utils.c
+++ b/src/parse-utils.c
@@ -50,31 +50,15 @@ void __weak tep_warning(const char *fmt, ...)
 	va_end(ap);
 }
 
-void __vpr_stat(const char *fmt, va_list ap)
-{
-	vprintf(fmt, ap);
-	printf("\n");
-}
 
-void __pr_stat(const char *fmt, ...)
+void tep_info(const char *fmt, ...)
 {
 	va_list ap;
 
-	va_start(ap, fmt);
-	__vpr_stat(fmt, ap);
-	va_end(ap);
-}
-
-void __weak vpr_stat(const char *fmt, va_list ap)
-{
-	__vpr_stat(fmt, ap);
-}
-
-void __weak pr_stat(const char *fmt, ...)
-{
-	va_list ap;
+	if (log_level < TEP_LOG_INFO)
+		return;
 
 	va_start(ap, fmt);
-	__vpr_stat(fmt, ap);
+	tep_vwarning("libtraceevent", fmt, ap);
 	va_end(ap);
 }
-- 
2.31.1

[PATCH v2 3/4] libtraceevent: Rename tep_vwarning() to tep_vprint()

[Tzvetomir Stoyanov (VMware)]

Renamed the existing weak function tep_vwarning() to tep_vprint(), to
match its purpose. This function is used to print library logs with any
log severity, not only warnings.

Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 src/event-utils.h |  5 +++--
 src/parse-utils.c | 27 ++++++++++++++++++++++-----
 2 files changed, 25 insertions(+), 7 deletions(-)

diff --git a/src/event-utils.h b/src/event-utils.h
index 1951557..0617a28 100644
--- a/src/event-utils.h
+++ b/src/event-utils.h
@@ -9,10 +9,11 @@
 #include <ctype.h>
 #include <stdarg.h>
 
+void tep_warning(const char *fmt, ...);
 void tep_info(const char *fmt, ...);
 /* Can be overridden */
-void tep_warning(const char *fmt, ...);
-int tep_vwarning(const char *name, const char *fmt, va_list ap);
+int tep_vprint(const char *name, enum tep_loglevel level,
+	       bool print_err, const char *fmt, va_list ap);
 
 #define min(x, y) ({				\
 	typeof(x) _min1 = (x);			\
diff --git a/src/parse-utils.c b/src/parse-utils.c
index b997823..7510157 100644
--- a/src/parse-utils.c
+++ b/src/parse-utils.c
@@ -24,11 +24,28 @@ void tep_set_loglevel(enum tep_loglevel level)
 	log_level = level;
 }
 
-int __weak tep_vwarning(const char *name, const char *fmt, va_list ap)
+/**
+ * tep_vprint - print library log messages
+ * @name: name of the library.
+ * @level: severity of the log message. This parameter is not used in this implementation, but as
+ *	   the function is weak and can be overridden, having the log level could be useful
+ *	   for other implementations.
+ * @print_err: whether to print the errno, if non zero.
+ * @fmt: printf format string of the message.
+ * @ap: list of printf parameters.
+ *
+ * This function is used to print all messages from traceevent, tracefs and trace-cmd libraries.
+ * It is defined as weak, so the application that uses those libraries can override it in order
+ * to implement its own logic for printing library logs.
+ *
+ * Return the value of errno at the function enter.
+ */
+int __weak tep_vprint(const char *name, enum tep_loglevel level,
+		      bool print_err, const char *fmt, va_list ap)
 {
 	int ret = errno;
 
-	if (errno)
+	if (errno && print_err)
 		perror(name);
 
 	fprintf(stderr, "  ");
@@ -38,7 +55,7 @@ int __weak tep_vwarning(const char *name, const char *fmt, va_list ap)
 	return ret;
 }
 
-void __weak tep_warning(const char *fmt, ...)
+void tep_warning(const char *fmt, ...)
 {
 	va_list ap;
 
@@ -46,7 +63,7 @@ void __weak tep_warning(const char *fmt, ...)
 		return;
 
 	va_start(ap, fmt);
-	tep_vwarning("libtraceevent", fmt, ap);
+	tep_vprint("libtraceevent", TEP_LOG_WARNING, true, fmt, ap);
 	va_end(ap);
 }
 
@@ -59,6 +76,6 @@ void tep_info(const char *fmt, ...)
 		return;
 
 	va_start(ap, fmt);
-	tep_vwarning("libtraceevent", fmt, ap);
+	tep_vprint("libtraceevent", TEP_LOG_INFO, false, fmt, ap);
 	va_end(ap);
 }
-- 
2.31.1

Re: [PATCH v2 3/4] libtraceevent: Rename tep_vwarning() to tep_vprint()

[Steven Rostedt]

On Fri,  7 May 2021 12:50:21 +0300
"Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com> wrote:

> diff --git a/src/event-utils.h b/src/event-utils.h
> index 1951557..0617a28 100644
> --- a/src/event-utils.h
> +++ b/src/event-utils.h
> @@ -9,10 +9,11 @@
>  #include <ctype.h>
>  #include <stdarg.h>
>  
> +void tep_warning(const char *fmt, ...);
>  void tep_info(const char *fmt, ...);
>  /* Can be overridden */
> -void tep_warning(const char *fmt, ...);
> -int tep_vwarning(const char *name, const char *fmt, va_list ap);
> +int tep_vprint(const char *name, enum tep_loglevel level,
> +	       bool print_err, const char *fmt, va_list ap);
>  
>  #define min(x, y) ({				\
>  	typeof(x) _min1 = (x);			\

I have the following build error on trace-cmd:

In file included from trace-util.c:23:
/usr/local/include/traceevent/event-utils.h:16:9: error: unknown type name ‘bool’
   16 |         bool print_err, const char *fmt, va_list ap);
      |         ^~~~

Needs to include <stdbool.h> in event-utils.h, can not rely that this
would exist in the use cases.

I'll add it to this patch, unless I find other issues for a v3.

-- Steve

[PATCH v2 4/4] libtraceevent: Document new log functionality

[Tzvetomir Stoyanov (VMware)]

Updated man pages with the new log API and log levels.

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

diff --git a/Documentation/libtraceevent-log.txt b/Documentation/libtraceevent-log.txt
new file mode 100644
index 0000000..0aee21d
--- /dev/null
+++ b/Documentation/libtraceevent-log.txt
@@ -0,0 +1,90 @@
+libtraceevent(3)
+================
+
+NAME
+----
+tep_set_loglevel - Set log level of the library
+
+SYNOPSIS
+--------
+[verse]
+--
+*#include <event-parse.h>*
+
+enum *tep_loglevel* {
+	TEP_LOG_NONE = 0,
+	TEP_LOG_CRITICAL,
+	TEP_LOG_ERROR,
+	TEP_LOG_WARNING,
+	TEP_LOG_INFO,
+	TEP_LOG_DEBUG,
+	TEP_LOG_ALL
+};
+
+int *tep_set_loglevel*(enum tep_loglevel _level_);
+
+--
+DESCRIPTION
+-----------
+The _tep_set_loglevel()_ function sets the level of the library logs that will be printed
+on the console. Library log levels are:
+[verse]
+--
+	_TEP_LOG_NONE_ - Do not print any logs.
+	_TEP_LOG_CRITICAL_ - Print critical logs, problem that may case a crash.
+	_TEP_LOG_ERROR_ - Print error logs, problem that could break the main logic of an API.
+	_TEP_LOG_WARNING_ - Print warnings, problem that could limit the result of an API.
+	_TEP_LOG_INFO_ - Print information about normal execution of an API.
+	_TEP_LOG_DEBUG_ - Print debug information.
+	_TEP_LOG_ALL_ - Print logs from all 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_.
+
+
+EXAMPLE
+-------
+[source,c]
+--
+#include <event-parse.h>
+
+tep_set_loglevel(TEP_LOG_ALL);
+...
+/* call libtraceevent APIs and observe any logs they produce */
+...
+tep_set_loglevel(TEP_LOG_CRITICAL);
+--
+
+FILES
+-----
+[verse]
+--
+*event-parse.h*
+	Header file to include in order to have access to the library APIs.
+*-ltraceevent*
+	Linker switch to add when building a program that uses the library.
+--
+
+SEE ALSO
+--------
+_libtraceevent(3)_, _trace-cmd(1)_
+
+AUTHOR
+------
+[verse]
+--
+*Steven Rostedt* <rostedt@goodmis.org>, author of *libtraceevent*.
+*Tzvetomir Stoyanov* <tz.stoyanov@gmail.com>, author of this man page.
+--
+REPORTING BUGS
+--------------
+Report bugs to  <linux-trace-devel@vger.kernel.org>
+
+LICENSE
+-------
+libtraceevent is Free Software licensed under the GNU LGPL 2.1
+
+RESOURCES
+---------
+https://git.kernel.org/pub/scm/libs/libtrace/libtraceevent.git/
diff --git a/Documentation/libtraceevent.txt b/Documentation/libtraceevent.txt
index 3365455..d42b5c9 100644
--- a/Documentation/libtraceevent.txt
+++ b/Documentation/libtraceevent.txt
@@ -127,6 +127,9 @@ Endian related APIs:
 	bool *tep_is_local_bigendian*(struct tep_handle pass:[*]_tep_);
 	void *tep_set_local_bigendian*(struct tep_handle pass:[*]_tep_, enum tep_endian _endian_);
 
+Control library logs:
+	int *tep_set_loglevel*(enum tep_loglevel _level_);
+
 Trace sequences:
 *#include <trace-seq.h>*
 	void *trace_seq_init*(struct trace_seq pass:[*]_s_);
-- 
2.31.1