[PATCH] trace-cmd: Suppress trace library warnings

[PATCH] trace-cmd: Suppress trace library warnings

[Tzvetomir Stoyanov (VMware)]

Suppress all warnings from libtraceevent, libtracefs and libtracecmd if
the trace-cmd application does not run in debug mode.

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

diff --git a/tracecmd/trace-cmd.c b/tracecmd/trace-cmd.c
index 7376c5a5..7de0671e 100644
--- a/tracecmd/trace-cmd.c
+++ b/tracecmd/trace-cmd.c
@@ -35,6 +35,23 @@ void warning(const char *fmt, ...)
 	fprintf(stderr, "\n");
 }
 
+int tep_vwarning(const char *name, const char *fmt, va_list ap)
+{
+	int ret = errno;
+
+	if (!tracecmd_get_debug())
+		return ret;
+
+	if (errno)
+		perror(name);
+
+	fprintf(stderr, "  ");
+	vfprintf(stderr, fmt, ap);
+	fprintf(stderr, "\n");
+
+	return ret;
+}
+
 void pr_stat(const char *fmt, ...)
 {
 	va_list ap;
-- 
2.30.2

Re: [PATCH] trace-cmd: Suppress trace library warnings

[Steven Rostedt]

On Thu, 15 Apr 2021 11:03:16 +0300
"Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com> wrote:

> Suppress all warnings from libtraceevent, libtracefs and libtracecmd if
> the trace-cmd application does not run in debug mode.

Actually, don't we have a -q option to turn off warnings from trace-cmd?

From the man page:

       -q
           Quiet non critical warnings.

Which I see, currently doesn't work, but should. Not being able to parse
events is something we should keep displaying by default, but it should
not be displayed if -q is on the command line.

-- Steve

> 
> Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
> ---
>  tracecmd/trace-cmd.c | 17 +++++++++++++++++
>  1 file changed, 17 insertions(+)
> 
> diff --git a/tracecmd/trace-cmd.c b/tracecmd/trace-cmd.c
> index 7376c5a5..7de0671e 100644
> --- a/tracecmd/trace-cmd.c
> +++ b/tracecmd/trace-cmd.c
> @@ -35,6 +35,23 @@ void warning(const char *fmt, ...)
>  	fprintf(stderr, "\n");
>  }
>  
> +int tep_vwarning(const char *name, const char *fmt, va_list ap)
> +{
> +	int ret = errno;
> +
> +	if (!tracecmd_get_debug())
> +		return ret;
> +
> +	if (errno)
> +		perror(name);
> +
> +	fprintf(stderr, "  ");
> +	vfprintf(stderr, fmt, ap);
> +	fprintf(stderr, "\n");
> +
> +	return ret;
> +}
> +
>  void pr_stat(const char *fmt, ...)
>  {
>  	va_list ap;

Re: [PATCH] trace-cmd: Suppress trace library warnings

[Tzvetomir Stoyanov]

On Thu, Apr 15, 2021 at 4:34 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Thu, 15 Apr 2021 11:03:16 +0300
> "Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com> wrote:
>
> > Suppress all warnings from libtraceevent, libtracefs and libtracecmd if
> > the trace-cmd application does not run in debug mode.
>
> Actually, don't we have a -q option to turn off warnings from trace-cmd?
>
> From the man page:
>
>        -q
>            Quiet non critical warnings.
>
> Which I see, currently doesn't work, but should. Not being able to parse
> events is something we should keep displaying by default, but it should
> not be displayed if -q is on the command line.
>

I can fix "-q" to suppress warnings from all trace libraries, but the
problem is that "-q" is not set by default. These "Not being able to
parse" messages could be very annoying in some cases and as I
understood they are not critical ? The other problem is that not all
trace-cmd commands have the "-q" option, but almost all of them need a
tep handler that could cause printing of these messages.
Yodan found one more issue, the pr_stat() libtraceevent function is
not affected by tep_vwarning() redefine. It prints statistics on
KernelShark startup. I think we should add some kind of priorities of
all those library messages and decide which of them when will be
printed.  It makes sense only for fatal library messages to be printed
by default, if the "-q" option is not set. All others should be
visible only if trace-cmd runs in debug mode.

> -- Steve
>
[...]


--
Tzvetomir (Ceco) Stoyanov
VMware Open Source Technology Center

Re: [PATCH] trace-cmd: Suppress trace library warnings

[Steven Rostedt]

On Fri, 16 Apr 2021 13:14:01 +0300
Tzvetomir Stoyanov <tz.stoyanov@gmail.com> wrote:

> I can fix "-q" to suppress warnings from all trace libraries, but the
> problem is that "-q" is not set by default. These "Not being able to
> parse" messages could be very annoying in some cases and as I
> understood they are not critical ? The other problem is that not all
> trace-cmd commands have the "-q" option, but almost all of them need a
> tep handler that could cause printing of these messages.
> Yodan found one more issue, the pr_stat() libtraceevent function is
> not affected by tep_vwarning() redefine. It prints statistics on
> KernelShark startup. I think we should add some kind of priorities of
> all those library messages and decide which of them when will be
> printed.  It makes sense only for fatal library messages to be printed
> by default, if the "-q" option is not set. All others should be
> visible only if trace-cmd runs in debug mode.

In principle I agree, but I have mixed feelings about this, because these
messages have helped me in the past to fix something. And not that I was
debugging it. I would trace an event and this would warn on it, and then I
would know the event had issues.

But I do find that they are more annoying when it's showing too much,
especially on "-e all" runs. Personally, I would love to only show those
warnings if the record was on a subset of events, and not all of them.
Because when I specify events, and it fails to parse, then I really do care
about that.

I wonder if we should do the following:

On record, if its not "-e all" then add an option that tells report that
not all events are traced. And it will allow for showing of failed to parse
events by default, and quieted by "-q". If that option does not exist, then
only show the failed parsings if "--debug" is set.

That is, if the user specified events, they should care if they parse or
not. But if they just said "-e all" then they probably do not care, because
there's going to be events that do not parse.

Thoughts?


As for pr_stat(), I think we should rename it to tep_info() and tep_vinfo()
that acts just like tep_warning(), except it is for informational output
(stdout instead of stderr). This is similar to what the kernel has.

Since tep_vwarning() takes a name, so can tep_vinfo(), and I was thinking
that we should expose this string to the application.

extern const char *tep_name;

As well for libtracefs:

extern const char *tracefs_name;

Then in tep_warning(), we could do things like:

	if (name == tep_name) {
		/* do something for libtraceevent errors */
	} else if (name == tracefs_name) {
		/* do something for libtracefs errors */
	}

Instead of doing the error prone:

	if (!strcmp(name, "libtraceevent")) {
		[..]
	} else if (!strcmp(name, "libtracefs")) {
		[..]
	}

-- Steve

Re: [PATCH] trace-cmd: Suppress trace library warnings

[Steven Rostedt]

On Fri, 16 Apr 2021 09:59:08 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> 
> As for pr_stat(), I think we should rename it to tep_info() and tep_vinfo()
> that acts just like tep_warning(), except it is for informational output
> (stdout instead of stderr). This is similar to what the kernel has.
> 
> Since tep_vwarning() takes a name, so can tep_vinfo(), and I was thinking
> that we should expose this string to the application.
> 

Oh, and we could add a tep_critical() and tep_vcritical() which means that
the error is something really bad happened, (like failed to allocate).

-- Steve

Re: [PATCH] trace-cmd: Suppress trace library warnings

[Steven Rostedt]

On Fri, 16 Apr 2021 10:01:18 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Fri, 16 Apr 2021 09:59:08 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > 
> > As for pr_stat(), I think we should rename it to tep_info() and tep_vinfo()
> > that acts just like tep_warning(), except it is for informational output
> > (stdout instead of stderr). This is similar to what the kernel has.
> > 
> > Since tep_vwarning() takes a name, so can tep_vinfo(), and I was thinking
> > that we should expose this string to the application.
> >   
> 
> Oh, and we could add a tep_critical() and tep_vcritical() which means that
> the error is something really bad happened, (like failed to allocate).

Any thoughts on this?

-- Steve

Re: [PATCH] trace-cmd: Suppress trace library warnings

[Tzvetomir Stoyanov]

On Thu, Apr 22, 2021 at 11:25 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Fri, 16 Apr 2021 10:01:18 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
>
> > On Fri, 16 Apr 2021 09:59:08 -0400
> > Steven Rostedt <rostedt@goodmis.org> wrote:
> >
> > >
> > > As for pr_stat(), I think we should rename it to tep_info() and tep_vinfo()
> > > that acts just like tep_warning(), except it is for informational output
> > > (stdout instead of stderr). This is similar to what the kernel has.
> > >
> > > Since tep_vwarning() takes a name, so can tep_vinfo(), and I was thinking
> > > that we should expose this string to the application.
> > >
> >
> > Oh, and we could add a tep_critical() and tep_vcritical() which means that
> > the error is something really bad happened, (like failed to allocate).
>
> Any thoughts on this?

The "[PATCH 0/8] Changes to trace-cmd logs" patchset supersedes this.


>
> -- Steve



--
Tzvetomir (Ceco) Stoyanov
VMware Open Source Technology Center

[PATCH 0/3] Fix overflow when applying tsc2nsec calculations

[Tzvetomir Stoyanov (VMware)]

Verify that applying tsc2nsec corrections on the recorded timestamps will not
cause an overflow. When recording the trace, in case of tsc2nsec clock, get
the first TSC timestamp as offset to be used in tsc2nsec conversion.


Tzvetomir Stoyanov (VMware) (3):
  trace-cmd library: Add new trace-cmd library APIs for guest ts
    corrections
  trace-cmd library: Add check before applying tsc2nsec offset
  trace-cmd: Get the timestamp of the first recorded event as TSC offset

 .../include/private/trace-cmd-private.h       |  18 ++-
 lib/trace-cmd/trace-input.c                   | 116 ++------------
 lib/trace-cmd/trace-timesync.c                | 113 +++++++++++---
 tracecmd/include/trace-local.h                |   1 +
 tracecmd/trace-record.c                       | 146 ++++++++++++++----
 5 files changed, 240 insertions(+), 154 deletions(-)

-- 
2.30.2

[PATCH] trace-cmd: Suppress trace library warnings

[Tzvetomir Stoyanov (VMware)]

Suppress all warnings from libtraceevent, libtracefs and libtracecmd if
the trace-cmd application does not run in debug mode.

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

diff --git a/tracecmd/trace-cmd.c b/tracecmd/trace-cmd.c
index 7376c5a5..7de0671e 100644
--- a/tracecmd/trace-cmd.c
+++ b/tracecmd/trace-cmd.c
@@ -35,6 +35,23 @@ void warning(const char *fmt, ...)
 	fprintf(stderr, "\n");
 }
 
+int tep_vwarning(const char *name, const char *fmt, va_list ap)
+{
+	int ret = errno;
+
+	if (!tracecmd_get_debug())
+		return ret;
+
+	if (errno)
+		perror(name);
+
+	fprintf(stderr, "  ");
+	vfprintf(stderr, fmt, ap);
+	fprintf(stderr, "\n");
+
+	return ret;
+}
+
 void pr_stat(const char *fmt, ...)
 {
 	va_list ap;
-- 
2.30.2