All of lore.kernel.org
 help / color / mirror / Atom feed
* Re: efficient use of LTTng in legacy codebase
       [not found] <ECCC3645D4115E4293D3E8C0EB22F09C20D363@ESESSMB109.ericsson.se>
@ 2013-12-12  0:47 ` Mathieu Desnoyers
       [not found] ` <38714154.84070.1386809251111.JavaMail.zimbra@efficios.com>
  1 sibling, 0 replies; 12+ messages in thread
From: Mathieu Desnoyers @ 2013-12-12  0:47 UTC (permalink / raw)
  To: Máté Ferenczy; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 2905 bytes --]

----- Original Message -----

> From: "Máté Ferenczy" <mate.ferenczy@ericsson.com>
> To: "mathieu desnoyers" <mathieu.desnoyers@efficios.com>
> Cc: lttng-dev@lists.lttng.org
> Sent: Wednesday, December 11, 2013 6:52:22 PM
> Subject: RE: efficient use of LTTng in legacy codebase

> I found this email thread:
> https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html

> According to this I could just check
> caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave claims
> that this state will stay true even if the tracepoint is disabled. Is there
> anything else I should check for?

I would recommend doing this in the UST probe provider instead. Within the TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, you could parse the format string there in the last argument of a ctf_string() (a statement expression). The format string would be received as parameter by the tracepoint, along with a variable arg list (...). In the probe, it would be turned into a va_list (see stdarg(3)), and the parameters could be decoded into a string there. This has the benefit of moving the serialization call out-of-line into the probe provider rather than clobbering the tracepoint call site. 

Thoughts ? 

Thanks, 

Mathieu 

> Thanks,

> Mate

> From: Máté Ferenczy
> Sent: Wednesday, December 11, 2013 12:17 PM
> To: 'mathieu.desnoyers@efficios.com'
> Cc: 'lttng-dev@lists.lttng.org'
> Subject: efficient use of LTTng in legacy codebase

> Hello Mathieu,

> Our team was asked to support LTTng UST solution in a legacy codebase. The
> existing codebase is fairly large, and the requirement is that we provide
> all the existing logs and debugs in the system as LTTng traces.

> The planned solution so far was just to pass everything we have as text
> (strings) to LTTng. For that we obviously have to convert the printf-like
> format string and parameter list to a string by calling snprintf before
> giving the string to the LTTng API. That would however mean, that these
> snprintfs are getting called every time even if there is no listener/active
> trace session for the given trace. In this case, all those unnecessary
> snprintf calls may end up significantly impacting the performance of our
> applications.

> In order to work around this, we were thinking that if there was a way to
> query the LTTng library from our application code whether there is an active
> tracing session for the given trace level, we could avoid calling those
> snprintfs in case they are not needed. Do you think it would be feasible to
> easily get this data from LTTng lib? If yes, can you provide us some
> pointers where to look at in order to do those changes ourselves?

> Any suggestions are welcome.

> Thank you,

> Mate Ferenczy

-- 
Mathieu Desnoyers 
EfficiOS Inc. 
http://www.efficios.com 

[-- Attachment #1.2: Type: text/html, Size: 5417 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
       [not found] ` <38714154.84070.1386809251111.JavaMail.zimbra@efficios.com>
@ 2013-12-12  1:52   ` Máté Ferenczy
       [not found]   ` <ECCC3645D4115E4293D3E8C0EB22F09C20D3F6@ESESSMB109.ericsson.se>
  1 sibling, 0 replies; 12+ messages in thread
From: Máté Ferenczy @ 2013-12-12  1:52 UTC (permalink / raw)
  To: Mathieu Desnoyers; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 3766 bytes --]

It sounds great, I like the idea. Just to make sure I understand your suggestion, are we talking about converting the variable argument list to string in include/lttng/ust-tracepoint-event-write.h?

For example:
#define ctf_format_string(_item, …)                               \
        do {                                                      \
            char _buf[BUF_MAXLEN];                               \
            snprintf(buf, sizeof(_buf), __VA_ARGS__);            \
            _ctf_string(_item, _buf, 0);                         \
       } while(0)

Or do you have some better place to put this logic?

Thanks,
Mate

From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
Sent: Wednesday, December 11, 2013 4:48 PM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org
Subject: Re: efficient use of LTTng in legacy codebase

________________________________
From: "Máté Ferenczy" <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To: "mathieu desnoyers" <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Sent: Wednesday, December 11, 2013 6:52:22 PM
Subject: RE: efficient use of LTTng in legacy codebase

I found this email thread: https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html
According to this I could just check caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave claims that this state will stay true even if the tracepoint is disabled. Is there anything else I should check for?

I would recommend doing this in the UST probe provider instead. Within the TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, you could parse the format string there in the last argument of a ctf_string() (a statement expression). The format string would be received as parameter by the tracepoint, along with a variable arg list (...). In the probe, it would be turned into a va_list (see stdarg(3)), and the parameters could be decoded into a string there. This has the benefit of moving the serialization call out-of-line into the probe provider rather than clobbering the tracepoint call site.

Thoughts ?

Thanks,

Mathieu

Thanks,
Mate

From: Máté Ferenczy
Sent: Wednesday, December 11, 2013 12:17 PM
To: 'mathieu.desnoyers@efficios.com'
Cc: 'lttng-dev@lists.lttng.org'
Subject: efficient use of LTTng in legacy codebase
Hello Mathieu,
Our team was asked to support LTTng UST solution in a legacy codebase. The existing codebase is fairly large, and the requirement is that we provide all the existing logs and debugs in the system as LTTng traces.
The planned solution so far was just to pass everything we have as text (strings) to LTTng. For that we obviously have to convert the printf-like format string and parameter list to a string by calling snprintf before giving the string to the LTTng API. That would however mean, that these snprintfs are getting called every time even if there is no listener/active trace session for the given trace. In this case, all those unnecessary snprintf calls may end up significantly impacting the performance of our applications.
In order to work around this, we were thinking that if there was a way to query the LTTng library from our application code whether there is an active tracing session for the given trace level, we could avoid calling those snprintfs in case they are not needed. Do you think it would be feasible to easily get this data from LTTng lib? If yes, can you provide us some pointers where to look at in order to do those changes ourselves?
Any suggestions are welcome.
Thank you,
Mate Ferenczy


--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

[-- Attachment #1.2: Type: text/html, Size: 13577 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
       [not found]   ` <ECCC3645D4115E4293D3E8C0EB22F09C20D3F6@ESESSMB109.ericsson.se>
@ 2013-12-12 12:35     ` Mathieu Desnoyers
       [not found]     ` <1206710241.84238.1386851719338.JavaMail.zimbra@efficios.com>
  1 sibling, 0 replies; 12+ messages in thread
From: Mathieu Desnoyers @ 2013-12-12 12:35 UTC (permalink / raw)
  To: Máté Ferenczy; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 4408 bytes --]

Just to speed things up, please have a look at the proposed UST patch. (it's not in mainline yet) 

This is specifically for a demo program example so far. 

Comments are welcome, 

Thanks, 

Mathieu 

----- Original Message -----

> From: "Máté Ferenczy" <mate.ferenczy@ericsson.com>
> To: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com>
> Cc: lttng-dev@lists.lttng.org
> Sent: Wednesday, December 11, 2013 8:52:30 PM
> Subject: RE: efficient use of LTTng in legacy codebase

> It sounds great, I like the idea. Just to make sure I understand your
> suggestion, are we talking about converting the variable argument list to
> string in include/lttng/ust-tracepoint-event-write.h?

> For example:

> #define ctf_format_string(_item, …) \

> do { \

> char _buf[BUF_MAXLEN]; \

> snprintf(buf, sizeof(_buf), __VA_ARGS__); \

> _ctf_string(_item, _buf, 0); \

> } while(0)

> Or do you have some better place to put this logic?

> Thanks,

> Mate

> From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
> Sent: Wednesday, December 11, 2013 4:48 PM
> To: Máté Ferenczy
> Cc: lttng-dev@lists.lttng.org
> Subject: Re: efficient use of LTTng in legacy codebase

> ----- Original Message -----

> > From: "Máté Ferenczy" < mate.ferenczy@ericsson.com >
> 
> > To: "mathieu desnoyers" < mathieu.desnoyers@efficios.com >
> 
> > Cc: lttng-dev@lists.lttng.org
> 
> > Sent: Wednesday, December 11, 2013 6:52:22 PM
> 
> > Subject: RE: efficient use of LTTng in legacy codebase
> 

> > I found this email thread:
> > https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html
> 

> > According to this I could just check
> > caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave
> > claims
> > that this state will stay true even if the tracepoint is disabled. Is there
> > anything else I should check for?
> 
> I would recommend doing this in the UST probe provider instead. Within the
> TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, you
> could parse the format string there in the last argument of a ctf_string()
> (a statement expression). The format string would be received as parameter
> by the tracepoint, along with a variable arg list (...). In the probe, it
> would be turned into a va_list (see stdarg(3)), and the parameters could be
> decoded into a string there. This has the benefit of moving the
> serialization call out-of-line into the probe provider rather than
> clobbering the tracepoint call site.

> Thoughts ?

> Thanks,

> Mathieu

> > Thanks,
> 

> > Mate
> 

> > From: Máté Ferenczy
> 
> > Sent: Wednesday, December 11, 2013 12:17 PM
> 
> > To: 'mathieu.desnoyers@efficios.com'
> 
> > Cc: 'lttng-dev@lists.lttng.org'
> 
> > Subject: efficient use of LTTng in legacy codebase
> 

> > Hello Mathieu,
> 

> > Our team was asked to support LTTng UST solution in a legacy codebase. The
> > existing codebase is fairly large, and the requirement is that we provide
> > all the existing logs and debugs in the system as LTTng traces.
> 

> > The planned solution so far was just to pass everything we have as text
> > (strings) to LTTng. For that we obviously have to convert the printf-like
> > format string and parameter list to a string by calling snprintf before
> > giving the string to the LTTng API. That would however mean, that these
> > snprintfs are getting called every time even if there is no listener/active
> > trace session for the given trace. In this case, all those unnecessary
> > snprintf calls may end up significantly impacting the performance of our
> > applications.
> 

> > In order to work around this, we were thinking that if there was a way to
> > query the LTTng library from our application code whether there is an
> > active
> > tracing session for the given trace level, we could avoid calling those
> > snprintfs in case they are not needed. Do you think it would be feasible to
> > easily get this data from LTTng lib? If yes, can you provide us some
> > pointers where to look at in order to do those changes ourselves?
> 

> > Any suggestions are welcome.
> 

> > Thank you,
> 

> > Mate Ferenczy
> 
> --

> Mathieu Desnoyers
> EfficiOS Inc.
> http://www.efficios.com

-- 
Mathieu Desnoyers 
EfficiOS Inc. 
http://www.efficios.com 

[-- Attachment #1.2: Type: text/html, Size: 13468 bytes --]

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: trace-fmt-demo.patch --]
[-- Type: text/x-patch; name=trace-fmt-demo.patch, Size: 13553 bytes --]

commit 2e589b6235396d29832ad9ff52ecc35a98df349f
Author: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Date:   Thu Dec 12 07:29:26 2013 -0500

    Add trace format demo
    
    Signed-off-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>

diff --git a/.gitignore b/.gitignore
index ce7c572..ece9f5b 100644
--- a/.gitignore
+++ b/.gitignore
@@ -36,6 +36,7 @@ doc/examples/easy-ust/sample
 doc/examples/hello-static-lib/hello
 doc/examples/gen-tp/sample
 doc/examples/gen-tp/sample_tracepoint.h
+doc/examples/demo-fmt-string/demo-fmt-string
 
 tests/hello/hello
 tests/hello.cxx/hello
diff --git a/doc/examples/Makefile.am b/doc/examples/Makefile.am
index 725806d..917976d 100644
--- a/doc/examples/Makefile.am
+++ b/doc/examples/Makefile.am
@@ -44,7 +44,7 @@ if NO_SHARED
 # disabled.
 else
 # Copies are for VPATH build support
-SUBDIRS_PROXY = easy-ust demo gen-tp hello-static-lib
+SUBDIRS_PROXY = easy-ust demo gen-tp hello-static-lib demo-fmt-string
 
 all-local:
 	@if [ x"$(srcdir)" != x"$(builddir)" ]; then \
diff --git a/doc/examples/demo-fmt-string/Makefile b/doc/examples/demo-fmt-string/Makefile
new file mode 100644
index 0000000..a3060d3
--- /dev/null
+++ b/doc/examples/demo-fmt-string/Makefile
@@ -0,0 +1,48 @@
+# Copyright (C) 2013  Jérémie Galarneau <jeremie.galarneau@efficios.com>
+#
+# THIS MATERIAL IS PROVIDED AS IS, WITH ABSOLUTELY NO WARRANTY EXPRESSED
+# OR IMPLIED. ANY USE IS AT YOUR OWN RISK.
+#
+# Permission is hereby granted to use or copy this program for any
+# purpose, provided the above notices are retained on all copies.
+# Permission to modify the code and to distribute modified code is
+# granted, provided the above notices are retained, and a notice that
+# the code was modified is included with the above copyright notice.
+#
+# This Makefile is not using automake so that users may see how to build
+# a program with tracepoint provider probes as stand-alone shared objects.
+#
+# This makefile is purposefully kept simple to support GNU and BSD make.
+
+CC = gcc
+LIBS = -ldl -llttng-ust	# On Linux
+#LIBS = -lc	# On BSD
+LOCAL_CPPFLAGS += -I.
+
+all: demo-fmt-string
+
+tp.o: tp.c ust_tests_demo_fmt_string.h trace-fmt.h
+	$(CC) $(CPPFLAGS) $(LOCAL_CPPFLAGS) $(CFLAGS) $(AM_CPPFLAGS) \
+		$(AM_CFLAGS) -fpic -c -o $@ $<
+
+trace-fmt.o: trace-fmt.c ust_tests_demo_fmt_string.h trace-fmt.h
+	$(CC) $(CPPFLAGS) $(LOCAL_CPPFLAGS) $(CFLAGS) $(AM_CPPFLAGS) \
+		$(AM_CFLAGS) -fpic -c -o $@ $<
+
+
+lttng-ust-provider-ust-tests-demo-fmt-string.a: tp.o trace-fmt.o
+	ar -rc $@ $+
+
+demo-fmt-string.o: demo-fmt-string.c trace-fmt.h
+	$(CC) $(CPPFLAGS) $(LOCAL_CPPFLAGS) $(CFLAGS) $(AM_CPPFLAGS) \
+		$(AM_CFLAGS) -c -o $@ $<
+
+demo-fmt-string: demo-fmt-string.o \
+		lttng-ust-provider-ust-tests-demo-fmt-string.a
+	$(CC) $(LDFLAGS) $(CFLAGS) $(AM_LDFLAGS) $(AM_CFLAGS) \
+		-o $@ demo-fmt-string.o \
+		lttng-ust-provider-ust-tests-demo-fmt-string.a $(LIBS)
+
+.PHONY: clean
+clean:
+	rm -f *.o *.a demo-fmt-string
diff --git a/doc/examples/demo-fmt-string/README b/doc/examples/demo-fmt-string/README
new file mode 100644
index 0000000..e069e73
--- /dev/null
+++ b/doc/examples/demo-fmt-string/README
@@ -0,0 +1,20 @@
+This is a demo application showing how to trace formatted strings into
+LTTng-UST.
+
+The simplest command to trace the demo program are:
+
+lttng create
+lttng enable-event -u "ust_tests_demo_fmt_string:event"
+lttng start
+./demo-fmt-string
+lttng stop
+lttng view
+lttng destroy
+
+The resulting lttng view output should look like this:
+
+[07:32:02.021045683] (+?.?????????) thinkos ust_tests_demo_fmt_string:event: { cpu_id = 2 }, { _msg_length = 46, msg = "This is a "mystring test" formatted 0 event 42" }
+[07:32:02.021062328] (+0.000016645) thinkos ust_tests_demo_fmt_string:event: { cpu_id = 2 }, { _msg_length = 46, msg = "This is a "mystring test" formatted 1 event 42" }
+[07:32:02.021066300] (+0.000003972) thinkos ust_tests_demo_fmt_string:event: { cpu_id = 2 }, { _msg_length = 46, msg = "This is a "mystring test" formatted 2 event 42" }
+[07:32:02.021069507] (+0.000003207) thinkos ust_tests_demo_fmt_string:event: { cpu_id = 2 }, { _msg_length = 46, msg = "This is a "mystring test" formatted 3 event 42" }
+[07:32:02.021072541] (+0.000003034) thinkos ust_tests_demo_fmt_string:event: { cpu_id = 2 }, { _msg_length = 46, msg = "This is a "mystring test" formatted 4 event 42" }
diff --git a/doc/examples/demo-fmt-string/demo-fmt-string.c b/doc/examples/demo-fmt-string/demo-fmt-string.c
new file mode 100644
index 0000000..7be4ec4
--- /dev/null
+++ b/doc/examples/demo-fmt-string/demo-fmt-string.c
@@ -0,0 +1,56 @@
+/*
+ * Copyright (C) 2009  Pierre-Marc Fournier
+ * Copyright (C) 2011  Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
+ *
+ * This library is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU Lesser General Public
+ * License as published by the Free Software Foundation; version 2.1 of
+ * the License.
+ *
+ * This library is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+ * Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public
+ * License along with this library; if not, write to the Free Software
+ * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301 USA
+ */
+
+#include <stdio.h>
+#include <unistd.h>
+#include <sys/mman.h>
+#include <stdarg.h>
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <fcntl.h>
+#include <signal.h>
+#include <string.h>
+#include <arpa/inet.h>
+#include <stdlib.h>
+
+#include "trace-fmt.h"
+
+int main(int argc, char **argv)
+{
+	int i;
+	int delay = 0;
+	const char *str = "mystring test";
+	long l = 0x42;
+
+	if (argc == 2)
+		delay = atoi(argv[1]);
+
+	fprintf(stderr, "Demo program starting.\n");
+
+	sleep(delay);
+
+	fprintf(stderr, "Tracing... ");
+	for (i = 0; i < 5; i++) {
+		ust_tests_demo_trace_fmt(
+			"This is a \"%s\" formatted %d event %lx",
+			str, i, l);
+	}
+	fprintf(stderr, " done.\n");
+	return 0;
+}
diff --git a/doc/examples/demo-fmt-string/tp.c b/doc/examples/demo-fmt-string/tp.c
new file mode 100644
index 0000000..47283ad
--- /dev/null
+++ b/doc/examples/demo-fmt-string/tp.c
@@ -0,0 +1,26 @@
+/*
+ * tp.c
+ *
+ * Copyright (c) 2011 Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+ * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
+ * SOFTWARE.
+ */
+
+#define TRACEPOINT_CREATE_PROBES
+#include "ust_tests_demo_fmt_string.h"
diff --git a/doc/examples/demo-fmt-string/trace-fmt.c b/doc/examples/demo-fmt-string/trace-fmt.c
new file mode 100644
index 0000000..1f59be4
--- /dev/null
+++ b/doc/examples/demo-fmt-string/trace-fmt.c
@@ -0,0 +1,47 @@
+/*
+ * Copyright (C) 2013  Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+ * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
+ * SOFTWARE.
+ */
+
+
+#define _GNU_SOURCE
+#include <stdio.h>
+
+#define TRACEPOINT_DEFINE
+#include "trace-fmt.h"
+
+void _ust_tests_demo_trace_fmt(const char *fmt, ...)
+{
+	va_list ap;
+	char *msg;
+	int len;
+
+	va_start(ap, fmt);
+	len = vasprintf(&msg, fmt, ap);
+	/* len does not include the final \0 */
+	if (len < 0)
+		goto end;
+	__tracepoint_cb_ust_tests_demo_fmt_string___event(msg, len);
+	free(msg);
+end:
+	va_end(ap);
+}
+
+
diff --git a/doc/examples/demo-fmt-string/trace-fmt.h b/doc/examples/demo-fmt-string/trace-fmt.h
new file mode 100644
index 0000000..73ef58d
--- /dev/null
+++ b/doc/examples/demo-fmt-string/trace-fmt.h
@@ -0,0 +1,37 @@
+#ifndef _LTTNG_UST_DEMO_TRACE_FMT_H
+#define _LTTNG_UST_DEMO_TRACE_FMT_H
+
+/*
+ * Copyright (C) 2013  Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+ * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
+ * SOFTWARE.
+ */
+
+#include "ust_tests_demo_fmt_string.h"
+
+void _ust_tests_demo_trace_fmt(const char *fmt, ...);
+
+#define ust_tests_demo_trace_fmt(fmt, ...)				\
+	do {								\
+		STAP_PROBEV(tracepoint_ust_tests_demo_fmt_string, event, ## __VA_ARGS__); \
+		if (caa_unlikely(__tracepoint_ust_tests_demo_fmt_string___event.state)) \
+			_ust_tests_demo_trace_fmt(fmt, ## __VA_ARGS__);	\
+	} while (0)
+
+#endif /* _LTTNG_UST_DEMO_TRACE_FMT_H */
diff --git a/doc/examples/demo-fmt-string/ust_tests_demo_fmt_string.h b/doc/examples/demo-fmt-string/ust_tests_demo_fmt_string.h
new file mode 100644
index 0000000..c1cff6b
--- /dev/null
+++ b/doc/examples/demo-fmt-string/ust_tests_demo_fmt_string.h
@@ -0,0 +1,46 @@
+#undef TRACEPOINT_PROVIDER
+#define TRACEPOINT_PROVIDER ust_tests_demo_fmt_string
+
+#if !defined(_TRACEPOINT_UST_TESTS_DEMO_FMT_STRING_H) || defined(TRACEPOINT_HEADER_MULTI_READ)
+#define _TRACEPOINT_UST_TESTS_DEMO_FMT_STRING_H
+
+/*
+ * Copyright (C) 2011  Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
+ *
+ * Permission is hereby granted, free of charge, to any person obtaining a copy
+ * of this software and associated documentation files (the "Software"), to deal
+ * in the Software without restriction, including without limitation the rights
+ * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+ * copies of the Software, and to permit persons to whom the Software is
+ * furnished to do so, subject to the following conditions:
+ *
+ * The above copyright notice and this permission notice shall be included in
+ * all copies or substantial portions of the Software.
+ *
+ * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+ * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+ * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+ * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+ * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+ * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
+ * SOFTWARE.
+ */
+
+#include <lttng/tracepoint.h>
+#include <stdarg.h>
+
+TRACEPOINT_EVENT(ust_tests_demo_fmt_string, event,
+	TP_ARGS(const char *, msg, unsigned int, len),
+	TP_FIELDS(
+		ctf_sequence_text(char, msg, msg, unsigned int, len)
+	)
+)
+TRACEPOINT_LOGLEVEL(ust_tests_demo_fmt_string, event, TRACE_DEBUG)
+
+#endif /* _TRACEPOINT_UST_TESTS_DEMO_FMT_STRING_H */
+
+#undef TRACEPOINT_INCLUDE
+#define TRACEPOINT_INCLUDE "./ust_tests_demo_fmt_string.h"
+
+/* This part must be outside ifdef protection */
+#include <lttng/tracepoint-event.h>

[-- Attachment #3: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply related	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
       [not found]     ` <1206710241.84238.1386851719338.JavaMail.zimbra@efficios.com>
@ 2013-12-12 17:30       ` Máté Ferenczy
       [not found]       ` <ECCC3645D4115E4293D3E8C0EB22F09C20D572@ESESSMB109.ericsson.se>
                         ` (2 subsequent siblings)
  3 siblings, 0 replies; 12+ messages in thread
From: Máté Ferenczy @ 2013-12-12 17:30 UTC (permalink / raw)
  To: Mathieu Desnoyers; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 4858 bytes --]

That’s even better, as far as I see we do not even have to touch the liblttng code itself.
Will get back with comments if any after testing.

Thanks so much!
mate


From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
Sent: Thursday, December 12, 2013 4:35 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org
Subject: Re: efficient use of LTTng in legacy codebase

Just to speed things up, please have a look at the proposed UST patch. (it's not in mainline yet)

This is specifically for a demo program example so far.

Comments are welcome,

Thanks,

Mathieu


________________________________
From: "Máté Ferenczy" <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Sent: Wednesday, December 11, 2013 8:52:30 PM
Subject: RE: efficient use of LTTng in legacy codebase

It sounds great, I like the idea. Just to make sure I understand your suggestion, are we talking about converting the variable argument list to string in include/lttng/ust-tracepoint-event-write.h?

For example:
#define ctf_format_string(_item, …)                               \
        do {                                                      \
            char _buf[BUF_MAXLEN];                               \
            snprintf(buf, sizeof(_buf), __VA_ARGS__);            \
            _ctf_string(_item, _buf, 0);                         \
       } while(0)

Or do you have some better place to put this logic?

Thanks,
Mate

From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
Sent: Wednesday, December 11, 2013 4:48 PM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Subject: Re: efficient use of LTTng in legacy codebase

________________________________
From: "Máté Ferenczy" <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To: "mathieu desnoyers" <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Sent: Wednesday, December 11, 2013 6:52:22 PM
Subject: RE: efficient use of LTTng in legacy codebase

I found this email thread: https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html
According to this I could just check caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave claims that this state will stay true even if the tracepoint is disabled. Is there anything else I should check for?

I would recommend doing this in the UST probe provider instead. Within the TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, you could parse the format string there in the last argument of a ctf_string() (a statement expression). The format string would be received as parameter by the tracepoint, along with a variable arg list (...). In the probe, it would be turned into a va_list (see stdarg(3)), and the parameters could be decoded into a string there. This has the benefit of moving the serialization call out-of-line into the probe provider rather than clobbering the tracepoint call site.

Thoughts ?

Thanks,

Mathieu

Thanks,
Mate

From: Máté Ferenczy
Sent: Wednesday, December 11, 2013 12:17 PM
To: 'mathieu.desnoyers@efficios.com'
Cc: 'lttng-dev@lists.lttng.org'
Subject: efficient use of LTTng in legacy codebase
Hello Mathieu,
Our team was asked to support LTTng UST solution in a legacy codebase. The existing codebase is fairly large, and the requirement is that we provide all the existing logs and debugs in the system as LTTng traces.
The planned solution so far was just to pass everything we have as text (strings) to LTTng. For that we obviously have to convert the printf-like format string and parameter list to a string by calling snprintf before giving the string to the LTTng API. That would however mean, that these snprintfs are getting called every time even if there is no listener/active trace session for the given trace. In this case, all those unnecessary snprintf calls may end up significantly impacting the performance of our applications.
In order to work around this, we were thinking that if there was a way to query the LTTng library from our application code whether there is an active tracing session for the given trace level, we could avoid calling those snprintfs in case they are not needed. Do you think it would be feasible to easily get this data from LTTng lib? If yes, can you provide us some pointers where to look at in order to do those changes ourselves?
Any suggestions are welcome.
Thank you,
Mate Ferenczy


--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com


--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

[-- Attachment #1.2: Type: text/html, Size: 19384 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
       [not found]       ` <ECCC3645D4115E4293D3E8C0EB22F09C20D572@ESESSMB109.ericsson.se>
@ 2013-12-15 12:56         ` Amit Margalit
       [not found]         ` <OFA420391C.226AC243-ONC2257C42.00460223-C2257C42.00471974@il.ibm.com>
  1 sibling, 0 replies; 12+ messages in thread
From: Amit Margalit @ 2013-12-15 12:56 UTC (permalink / raw)
  To: Máté Ferenczy; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 6327 bytes --]

The macro is elegant and solves the problem nicely.

I find that it does not make the biggest issue go away - the entire 
formatted string gets stored in the trace file multiple times.

The best solution would be:
To modify CTF and define a type that indicates a printf-style format 
string.
To have a LTTng macro that provides this string to the tracer, so that it 
can record it only once in the metadata.
To have the tracepoint store all the arguments in binary form, possibly 
with the addition of some identifying value of the format string.
And to have babeltrace (the CTF trace reader) perform the formatting 
off-line.

I mean - consider a trace message that includes a long format string, with 
say - 5 integer arguments. Something like:
"Buffer vacancy threshold warning: curr_limit=%d, curr_threshold=%d, 
channel_num=%d, high_mark=%d, hit_count=%d"

This stores > 105 bytes with every trace line. But the real information 
here is only 20 bytes (assuming the integers are 32-bits).

Storing the format string once in the metadata will effectively boost 
performance for a system trying to trace like this.

Amit Margalit
IBM XIV - Storage Reinvented
XIV-NAS Development Team
Tel. 03-689-7774
Fax. 03-689-7230



From:   Máté Ferenczy <mate.ferenczy@ericsson.com>
To:     Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc:     "lttng-dev@lists.lttng.org" <lttng-dev@lists.lttng.org>
Date:   12/12/2013 07:39 PM
Subject:        Re: [lttng-dev] efficient use of LTTng in legacy codebase



That?s even better, as far as I see we do not even have to touch the 
liblttng code itself.
Will get back with comments if any after testing.
 
Thanks so much! 
mate
 
 
From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com] 
Sent: Thursday, December 12, 2013 4:35 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org
Subject: Re: efficient use of LTTng in legacy codebase
 
Just to speed things up, please have a look at the proposed UST patch. 
(it's not in mainline yet)
 
This is specifically for a demo program example so far.
 
Comments are welcome,
 
Thanks,
 
Mathieu
 
 

From: "Máté Ferenczy" <mate.ferenczy@ericsson.com>
To: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com>
Cc: lttng-dev@lists.lttng.org
Sent: Wednesday, December 11, 2013 8:52:30 PM
Subject: RE: efficient use of LTTng in legacy codebase
 
It sounds great, I like the idea. Just to make sure I understand your 
suggestion, are we talking about converting the variable argument list to 
string in include/lttng/ust-tracepoint-event-write.h?
 
For example:
#define ctf_format_string(_item, ?)                               \
        do {                                                      \
            char _buf[BUF_MAXLEN];                               \
            snprintf(buf, sizeof(_buf), __VA_ARGS__);            \
            _ctf_string(_item, _buf, 0);                         \
       } while(0)
 
Or do you have some better place to put this logic?
 
Thanks,
Mate
 
From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com] 
Sent: Wednesday, December 11, 2013 4:48 PM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org
Subject: Re: efficient use of LTTng in legacy codebase
 

From: "Máté Ferenczy" <mate.ferenczy@ericsson.com>
To: "mathieu desnoyers" <mathieu.desnoyers@efficios.com>
Cc: lttng-dev@lists.lttng.org
Sent: Wednesday, December 11, 2013 6:52:22 PM
Subject: RE: efficient use of LTTng in legacy codebase
 
I found this email thread: 
https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html
According to this I could just check 
caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave 
claims that this state will stay true even if the tracepoint is disabled. 
Is there anything else I should check for?
 
I would recommend doing this in the UST probe provider instead. Within the 
TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, 
you could parse the format string there in the last argument of a 
ctf_string() (a statement expression). The format string would be received 
as parameter by the tracepoint, along with a variable arg list (...). In 
the probe, it would be turned into a va_list (see stdarg(3)), and the 
parameters could be decoded into a string there. This has the benefit of 
moving the serialization call out-of-line into the probe provider rather 
than clobbering the tracepoint call site.
 
Thoughts ?
 
Thanks,
 
Mathieu
 
Thanks,
Mate
 
From: Máté Ferenczy 
Sent: Wednesday, December 11, 2013 12:17 PM
To: 'mathieu.desnoyers@efficios.com'
Cc: 'lttng-dev@lists.lttng.org'
Subject: efficient use of LTTng in legacy codebase
Hello Mathieu,
Our team was asked to support LTTng UST solution in a legacy codebase. The 
existing codebase is fairly large, and the requirement is that we provide 
all the existing logs and debugs in the system as LTTng traces.
The planned solution so far was just to pass everything we have as text 
(strings) to LTTng. For that we obviously have to convert the printf-like 
format string and parameter list to a string by calling snprintf before 
giving the string to the LTTng API. That would however mean, that these 
snprintfs are getting called every time even if there is no 
listener/active trace session for the given trace. In this case, all those 
unnecessary snprintf calls may end up significantly impacting the 
performance of our applications.
In order to work around this, we were thinking that if there was a way to 
query the LTTng library from our application code whether there is an 
active tracing session for the given trace level, we could avoid calling 
those snprintfs in case they are not needed. Do you think it would be 
feasible to easily get this data from LTTng lib? If yes, can you provide 
us some pointers where to look at in order to do those changes ourselves?
Any suggestions are welcome.
Thank you,
Mate Ferenczy
 
 
-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com
 
 
-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev


[-- Attachment #1.2: Type: text/html, Size: 13481 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
       [not found]         ` <OFA420391C.226AC243-ONC2257C42.00460223-C2257C42.00471974@il.ibm.com>
@ 2013-12-16  1:11           ` Máté Ferenczy
       [not found]           ` <ECCC3645D4115E4293D3E8C0EB22F09C22CC8E@ESESSMB109.ericsson.se>
  1 sibling, 0 replies; 12+ messages in thread
From: Máté Ferenczy @ 2013-12-16  1:11 UTC (permalink / raw)
  To: Amit Margalit; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 7403 bytes --]

I agree that in the long term it would be nice if the trace reader could perform the formatting.

However, I am not sure how #2 would work if the format strings and argument lists are passed through a couple of function calls before calling the tracepoint API (which is the case in our code).

From: Amit Margalit [mailto:AMITM@il.ibm.com]
Sent: Sunday, December 15, 2013 4:56 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org; Mathieu Desnoyers
Subject: Re: [lttng-dev] efficient use of LTTng in legacy codebase

The macro is elegant and solves the problem nicely.

I find that it does not make the biggest issue go away - the entire formatted string gets stored in the trace file multiple times.

The best solution would be:

  1.  To modify CTF and define a type that indicates a printf-style format string.

  1.  To have a LTTng macro that provides this string to the tracer, so that it can record it only once in the metadata.

  1.  To have the tracepoint store all the arguments in binary form, possibly with the addition of some identifying value of the format string.

  1.  And to have babeltrace (the CTF trace reader) perform the formatting off-line.

I mean - consider a trace message that includes a long format string, with say - 5 integer arguments. Something like:
"Buffer vacancy threshold warning: curr_limit=%d, curr_threshold=%d, channel_num=%d, high_mark=%d, hit_count=%d"

This stores > 105 bytes with every trace line. But the real information here is only 20 bytes (assuming the integers are 32-bits).

Storing the format string once in the metadata will effectively boost performance for a system trying to trace like this.

Amit Margalit
IBM XIV - Storage Reinvented
XIV-NAS Development Team
Tel. 03-689-7774
Fax. 03-689-7230



From:        Máté Ferenczy <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To:        Mathieu Desnoyers <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc:        "lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>" <lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>>
Date:        12/12/2013 07:39 PM
Subject:        Re: [lttng-dev] efficient use of LTTng in legacy codebase
________________________________



That's even better, as far as I see we do not even have to touch the liblttng code itself.
Will get back with comments if any after testing.

Thanks so much!
mate


From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
Sent: Thursday, December 12, 2013 4:35 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Subject: Re: efficient use of LTTng in legacy codebase

Just to speed things up, please have a look at the proposed UST patch. (it's not in mainline yet)

This is specifically for a demo program example so far.

Comments are welcome,

Thanks,

Mathieu


________________________________

From: "Máté Ferenczy" <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Sent: Wednesday, December 11, 2013 8:52:30 PM
Subject: RE: efficient use of LTTng in legacy codebase

It sounds great, I like the idea. Just to make sure I understand your suggestion, are we talking about converting the variable argument list to string in include/lttng/ust-tracepoint-event-write.h?

For example:
#define ctf_format_string(_item, ...)                               \
        do {                                                      \
            char _buf[BUF_MAXLEN];                               \
            snprintf(buf, sizeof(_buf), __VA_ARGS__);            \
            _ctf_string(_item, _buf, 0);                         \
       } while(0)

Or do you have some better place to put this logic?

Thanks,
Mate

From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
Sent: Wednesday, December 11, 2013 4:48 PM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Subject: Re: efficient use of LTTng in legacy codebase

________________________________

From: "Máté Ferenczy" <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To: "mathieu desnoyers" <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Sent: Wednesday, December 11, 2013 6:52:22 PM
Subject: RE: efficient use of LTTng in legacy codebase

I found this email thread: https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html
According to this I could just check caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave claims that this state will stay true even if the tracepoint is disabled. Is there anything else I should check for?

I would recommend doing this in the UST probe provider instead. Within the TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, you could parse the format string there in the last argument of a ctf_string() (a statement expression). The format string would be received as parameter by the tracepoint, along with a variable arg list (...). In the probe, it would be turned into a va_list (see stdarg(3)), and the parameters could be decoded into a string there. This has the benefit of moving the serialization call out-of-line into the probe provider rather than clobbering the tracepoint call site.

Thoughts ?

Thanks,

Mathieu

Thanks,
Mate

From: Máté Ferenczy
Sent: Wednesday, December 11, 2013 12:17 PM
To: 'mathieu.desnoyers@efficios.com'
Cc: 'lttng-dev@lists.lttng.org'
Subject: efficient use of LTTng in legacy codebase
Hello Mathieu,
Our team was asked to support LTTng UST solution in a legacy codebase. The existing codebase is fairly large, and the requirement is that we provide all the existing logs and debugs in the system as LTTng traces.
The planned solution so far was just to pass everything we have as text (strings) to LTTng. For that we obviously have to convert the printf-like format string and parameter list to a string by calling snprintf before giving the string to the LTTng API. That would however mean, that these snprintfs are getting called every time even if there is no listener/active trace session for the given trace. In this case, all those unnecessary snprintf calls may end up significantly impacting the performance of our applications.
In order to work around this, we were thinking that if there was a way to query the LTTng library from our application code whether there is an active tracing session for the given trace level, we could avoid calling those snprintfs in case they are not needed. Do you think it would be feasible to easily get this data from LTTng lib? If yes, can you provide us some pointers where to look at in order to do those changes ourselves?
Any suggestions are welcome.
Thank you,
Mate Ferenczy


--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com<http://www.efficios.com/>


--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com<http://www.efficios.com/>_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

[-- Attachment #1.2: Type: text/html, Size: 24278 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
       [not found]           ` <ECCC3645D4115E4293D3E8C0EB22F09C22CC8E@ESESSMB109.ericsson.se>
@ 2013-12-17  7:35             ` Amit Margalit
       [not found]             ` <OF7A09BD18.DB100453-ONC2257C44.0025741C-C2257C44.0029B7A4@il.ibm.com>
  1 sibling, 0 replies; 12+ messages in thread
From: Amit Margalit @ 2013-12-17  7:35 UTC (permalink / raw)
  To: Máté Ferenczy; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 7805 bytes --]

You are absolutely right. However, looking at several existing code bases 
that I am working with (our internal code, and a couple of open-source 
projects I am adding LTTng support for), it is clear that the vast 
majority of existing debug log statements have the following general form:

DEBUG_MACRO ( some_args, "lliteral format string", more args )

Amit

Amit Margalit
IBM XIV - Storage Reinvented
XIV-NAS Development Team
Tel. 03-689-7774
Fax. 03-689-7230



From:   Máté Ferenczy <mate.ferenczy@ericsson.com>
To:     Amit Margalit/Israel/IBM@IBMIL
Cc:     "lttng-dev@lists.lttng.org" <lttng-dev@lists.lttng.org>, Mathieu 
Desnoyers <mathieu.desnoyers@efficios.com>
Date:   12/16/2013 03:11 AM
Subject:        RE: [lttng-dev] efficient use of LTTng in legacy codebase



I agree that in the long term it would be nice if the trace reader could 
perform the formatting.
 
However, I am not sure how #2 would work if the format strings and 
argument lists are passed through a couple of function calls before 
calling the tracepoint API (which is the case in our code).
 
From: Amit Margalit [mailto:AMITM@il.ibm.com] 
Sent: Sunday, December 15, 2013 4:56 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org; Mathieu Desnoyers
Subject: Re: [lttng-dev] efficient use of LTTng in legacy codebase
 
The macro is elegant and solves the problem nicely. 

I find that it does not make the biggest issue go away - the entire 
formatted string gets stored in the trace file multiple times. 

The best solution would be: 
1.      To modify CTF and define a type that indicates a printf-style 
format string. 
2.      To have a LTTng macro that provides this string to the tracer, so 
that it can record it only once in the metadata. 
3.      To have the tracepoint store all the arguments in binary form, 
possibly with the addition of some identifying value of the format string. 

4.      And to have babeltrace (the CTF trace reader) perform the 
formatting off-line.

I mean - consider a trace message that includes a long format string, with 
say - 5 integer arguments. Something like: 
"Buffer vacancy threshold warning: curr_limit=%d, curr_threshold=%d, 
channel_num=%d, high_mark=%d, hit_count=%d" 

This stores > 105 bytes with every trace line. But the real information 
here is only 20 bytes (assuming the integers are 32-bits). 

Storing the format string once in the metadata will effectively boost 
performance for a system trying to trace like this. 

Amit Margalit 
IBM XIV - Storage Reinvented 
XIV-NAS Development Team 
Tel. 03-689-7774 
Fax. 03-689-7230 



From:        Máté Ferenczy <mate.ferenczy@ericsson.com> 
To:        Mathieu Desnoyers <mathieu.desnoyers@efficios.com> 
Cc:        "lttng-dev@lists.lttng.org" <lttng-dev@lists.lttng.org> 
Date:        12/12/2013 07:39 PM 
Subject:        Re: [lttng-dev] efficient use of LTTng in legacy codebase 




That?s even better, as far as I see we do not even have to touch the 
liblttng code itself. 
Will get back with comments if any after testing. 
  
Thanks so much! 
mate 
  
  
From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com] 
Sent: Thursday, December 12, 2013 4:35 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org
Subject: Re: efficient use of LTTng in legacy codebase 
  
Just to speed things up, please have a look at the proposed UST patch. 
(it's not in mainline yet) 
  
This is specifically for a demo program example so far. 
  
Comments are welcome, 
  
Thanks, 
  
Mathieu 
  
  


From: "Máté Ferenczy" <mate.ferenczy@ericsson.com>
To: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com>
Cc: lttng-dev@lists.lttng.org
Sent: Wednesday, December 11, 2013 8:52:30 PM
Subject: RE: efficient use of LTTng in legacy codebase 
  
It sounds great, I like the idea. Just to make sure I understand your 
suggestion, are we talking about converting the variable argument list to 
string in include/lttng/ust-tracepoint-event-write.h? 
  
For example: 
#define ctf_format_string(_item, ?)                               \ 
        do {                                                      \ 
            char _buf[BUF_MAXLEN];                               \ 
            snprintf(buf, sizeof(_buf), __VA_ARGS__);            \ 
            _ctf_string(_item, _buf, 0);                         \ 
       } while(0) 
        
Or do you have some better place to put this logic? 
  
Thanks, 
Mate 
  
From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com] 
Sent: Wednesday, December 11, 2013 4:48 PM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org
Subject: Re: efficient use of LTTng in legacy codebase 
  


From: "Máté Ferenczy" <mate.ferenczy@ericsson.com>
To: "mathieu desnoyers" <mathieu.desnoyers@efficios.com>
Cc: lttng-dev@lists.lttng.org
Sent: Wednesday, December 11, 2013 6:52:22 PM
Subject: RE: efficient use of LTTng in legacy codebase 
  
I found this email thread: 
https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html 
According to this I could just check 
caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave 
claims that this state will stay true even if the tracepoint is disabled. 
Is there anything else I should check for? 
 
I would recommend doing this in the UST probe provider instead. Within the 
TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, 
you could parse the format string there in the last argument of a 
ctf_string() (a statement expression). The format string would be received 
as parameter by the tracepoint, along with a variable arg list (...). In 
the probe, it would be turned into a va_list (see stdarg(3)), and the 
parameters could be decoded into a string there. This has the benefit of 
moving the serialization call out-of-line into the probe provider rather 
than clobbering the tracepoint call site. 
 
Thoughts ? 
 
Thanks, 
 
Mathieu 
  
Thanks, 
Mate 
  
From: Máté Ferenczy 
Sent: Wednesday, December 11, 2013 12:17 PM
To: 'mathieu.desnoyers@efficios.com'
Cc: 'lttng-dev@lists.lttng.org'
Subject: efficient use of LTTng in legacy codebase 
Hello Mathieu, 
Our team was asked to support LTTng UST solution in a legacy codebase. The 
existing codebase is fairly large, and the requirement is that we provide 
all the existing logs and debugs in the system as LTTng traces. 
The planned solution so far was just to pass everything we have as text 
(strings) to LTTng. For that we obviously have to convert the printf-like 
format string and parameter list to a string by calling snprintf before 
giving the string to the LTTng API. That would however mean, that these 
snprintfs are getting called every time even if there is no 
listener/active trace session for the given trace. In this case, all those 
unnecessary snprintf calls may end up significantly impacting the 
performance of our applications. 
In order to work around this, we were thinking that if there was a way to 
query the LTTng library from our application code whether there is an 
active tracing session for the given trace level, we could avoid calling 
those snprintfs in case they are not needed. Do you think it would be 
feasible to easily get this data from LTTng lib? If yes, can you provide 
us some pointers where to look at in order to do those changes ourselves? 
Any suggestions are welcome. 
Thank you, 
Mate Ferenczy 
 
 
-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com 
 
 
-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

[-- Attachment #1.2: Type: text/html, Size: 18470 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
       [not found]             ` <OF7A09BD18.DB100453-ONC2257C44.0025741C-C2257C44.0029B7A4@il.ibm.com>
@ 2013-12-17 20:36               ` Máté Ferenczy
  0 siblings, 0 replies; 12+ messages in thread
From: Máté Ferenczy @ 2013-12-17 20:36 UTC (permalink / raw)
  To: Amit Margalit; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 8951 bytes --]

Yes, I agree that majority of the projects will pass this as macros. However, if there is an official solution for this problem from LTTng side, it would be nice if it could support the function-call way of passing the format string and variable argument list as well.

Thanks,
mate

From: Amit Margalit [mailto:AMITM@il.ibm.com]
Sent: Monday, December 16, 2013 11:36 PM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org; Mathieu Desnoyers
Subject: RE: [lttng-dev] efficient use of LTTng in legacy codebase

You are absolutely right. However, looking at several existing code bases that I am working with (our internal code, and a couple of open-source projects I am adding LTTng support for), it is clear that the vast majority of existing debug log statements have the following general form:

DEBUG_MACRO ( some_args, "lliteral format string", more args )

Amit

Amit Margalit
IBM XIV - Storage Reinvented
XIV-NAS Development Team
Tel. 03-689-7774
Fax. 03-689-7230



From:        Máté Ferenczy <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To:        Amit Margalit/Israel/IBM@IBMIL
Cc:        "lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>" <lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>>, Mathieu Desnoyers <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Date:        12/16/2013 03:11 AM
Subject:        RE: [lttng-dev] efficient use of LTTng in legacy codebase
________________________________



I agree that in the long term it would be nice if the trace reader could perform the formatting.

However, I am not sure how #2 would work if the format strings and argument lists are passed through a couple of function calls before calling the tracepoint API (which is the case in our code).

From: Amit Margalit [mailto:AMITM@il.ibm.com]
Sent: Sunday, December 15, 2013 4:56 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>; Mathieu Desnoyers
Subject: Re: [lttng-dev] efficient use of LTTng in legacy codebase

The macro is elegant and solves the problem nicely.

I find that it does not make the biggest issue go away - the entire formatted string gets stored in the trace file multiple times.

The best solution would be:
1.        To modify CTF and define a type that indicates a printf-style format string.
2.        To have a LTTng macro that provides this string to the tracer, so that it can record it only once in the metadata.
3.        To have the tracepoint store all the arguments in binary form, possibly with the addition of some identifying value of the format string.
4.        And to have babeltrace (the CTF trace reader) perform the formatting off-line.

I mean - consider a trace message that includes a long format string, with say - 5 integer arguments. Something like:
"Buffer vacancy threshold warning: curr_limit=%d, curr_threshold=%d, channel_num=%d, high_mark=%d, hit_count=%d"

This stores > 105 bytes with every trace line. But the real information here is only 20 bytes (assuming the integers are 32-bits).

Storing the format string once in the metadata will effectively boost performance for a system trying to trace like this.

Amit Margalit
IBM XIV - Storage Reinvented
XIV-NAS Development Team
Tel. 03-689-7774
Fax. 03-689-7230



From:        Máté Ferenczy <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To:        Mathieu Desnoyers <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc:        "lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>" <lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>>
Date:        12/12/2013 07:39 PM
Subject:        Re: [lttng-dev] efficient use of LTTng in legacy codebase
________________________________




That's even better, as far as I see we do not even have to touch the liblttng code itself.
Will get back with comments if any after testing.

Thanks so much!
mate


From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
Sent: Thursday, December 12, 2013 4:35 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Subject: Re: efficient use of LTTng in legacy codebase

Just to speed things up, please have a look at the proposed UST patch. (it's not in mainline yet)

This is specifically for a demo program example so far.

Comments are welcome,

Thanks,

Mathieu


________________________________


From: "Máté Ferenczy" <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Sent: Wednesday, December 11, 2013 8:52:30 PM
Subject: RE: efficient use of LTTng in legacy codebase

It sounds great, I like the idea. Just to make sure I understand your suggestion, are we talking about converting the variable argument list to string in include/lttng/ust-tracepoint-event-write.h?

For example:
#define ctf_format_string(_item, ...)                               \
       do {                                                      \
           char _buf[BUF_MAXLEN];                               \
           snprintf(buf, sizeof(_buf), __VA_ARGS__);            \
           _ctf_string(_item, _buf, 0);                         \
      } while(0)

Or do you have some better place to put this logic?

Thanks,
Mate

From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
Sent: Wednesday, December 11, 2013 4:48 PM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Subject: Re: efficient use of LTTng in legacy codebase

________________________________


From: "Máté Ferenczy" <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To: "mathieu desnoyers" <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Sent: Wednesday, December 11, 2013 6:52:22 PM
Subject: RE: efficient use of LTTng in legacy codebase

I found this email thread: https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html
According to this I could just check caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave claims that this state will stay true even if the tracepoint is disabled. Is there anything else I should check for?

I would recommend doing this in the UST probe provider instead. Within the TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, you could parse the format string there in the last argument of a ctf_string() (a statement expression). The format string would be received as parameter by the tracepoint, along with a variable arg list (...). In the probe, it would be turned into a va_list (see stdarg(3)), and the parameters could be decoded into a string there. This has the benefit of moving the serialization call out-of-line into the probe provider rather than clobbering the tracepoint call site.

Thoughts ?

Thanks,

Mathieu

Thanks,
Mate

From: Máté Ferenczy
Sent: Wednesday, December 11, 2013 12:17 PM
To: 'mathieu.desnoyers@efficios.com'
Cc: 'lttng-dev@lists.lttng.org'
Subject: efficient use of LTTng in legacy codebase
Hello Mathieu,
Our team was asked to support LTTng UST solution in a legacy codebase. The existing codebase is fairly large, and the requirement is that we provide all the existing logs and debugs in the system as LTTng traces.
The planned solution so far was just to pass everything we have as text (strings) to LTTng. For that we obviously have to convert the printf-like format string and parameter list to a string by calling snprintf before giving the string to the LTTng API. That would however mean, that these snprintfs are getting called every time even if there is no listener/active trace session for the given trace. In this case, all those unnecessary snprintf calls may end up significantly impacting the performance of our applications.
In order to work around this, we were thinking that if there was a way to query the LTTng library from our application code whether there is an active tracing session for the given trace level, we could avoid calling those snprintfs in case they are not needed. Do you think it would be feasible to easily get this data from LTTng lib? If yes, can you provide us some pointers where to look at in order to do those changes ourselves?
Any suggestions are welcome.
Thank you,
Mate Ferenczy


--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com<http://www.efficios.com/>


--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com<http://www.efficios.com/>_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

[-- Attachment #1.2: Type: text/html, Size: 28955 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
       [not found]     ` <1206710241.84238.1386851719338.JavaMail.zimbra@efficios.com>
  2013-12-12 17:30       ` Máté Ferenczy
       [not found]       ` <ECCC3645D4115E4293D3E8C0EB22F09C20D572@ESESSMB109.ericsson.se>
@ 2013-12-19  3:31       ` Máté Ferenczy
       [not found]       ` <ECCC3645D4115E4293D3E8C0EB22F09C233310@ESESSMB109.ericsson.se>
  3 siblings, 0 replies; 12+ messages in thread
From: Máté Ferenczy @ 2013-12-19  3:31 UTC (permalink / raw)
  To: Mathieu Desnoyers; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 5699 bytes --]

After some discussion, the following solution seems to be simpler and not dependent on LTTng UST internals:

#define tracepoint_for_format_string(provider, name, …) \
      do { \
            char msg_buf[MAX_BUFFER_SIZE]; \
            tracepoint(provider, name, my_snprintf(msg_buf, MAX_BUFFER_SIZE, __VA_ARGS__)); \
      } while (0)

my_snprintf should return the pointer to the msg_buf. Although this solution allocates the buffer on the stack even if the tracepoint is disabled, this should be a very fast operation, and as long as the buffer size is much smaller than the maximum stack size should be ok. Another option is to allocate memory inside the my_snprintf function by malloc, which would only be called if the tracepoint is enabled, however in those cases the memory allocation would be more expensive.

We would probably prefer this solution compared to the attached patch, as it is independent of LTTng implementation.

Any comments, suggestions are appreciated.

Thanks,
mate

From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
Sent: Thursday, December 12, 2013 4:35 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org
Subject: Re: efficient use of LTTng in legacy codebase

Just to speed things up, please have a look at the proposed UST patch. (it's not in mainline yet)

This is specifically for a demo program example so far.

Comments are welcome,

Thanks,

Mathieu


________________________________
From: "Máté Ferenczy" <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Sent: Wednesday, December 11, 2013 8:52:30 PM
Subject: RE: efficient use of LTTng in legacy codebase

It sounds great, I like the idea. Just to make sure I understand your suggestion, are we talking about converting the variable argument list to string in include/lttng/ust-tracepoint-event-write.h?

For example:
#define ctf_format_string(_item, …)                               \
        do {                                                      \
            char _buf[BUF_MAXLEN];                               \
            snprintf(buf, sizeof(_buf), __VA_ARGS__);            \
            _ctf_string(_item, _buf, 0);                         \
       } while(0)

Or do you have some better place to put this logic?

Thanks,
Mate

From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com]
Sent: Wednesday, December 11, 2013 4:48 PM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Subject: Re: efficient use of LTTng in legacy codebase

________________________________
From: "Máté Ferenczy" <mate.ferenczy@ericsson.com<mailto:mate.ferenczy@ericsson.com>>
To: "mathieu desnoyers" <mathieu.desnoyers@efficios.com<mailto:mathieu.desnoyers@efficios.com>>
Cc: lttng-dev@lists.lttng.org<mailto:lttng-dev@lists.lttng.org>
Sent: Wednesday, December 11, 2013 6:52:22 PM
Subject: RE: efficient use of LTTng in legacy codebase

I found this email thread: https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html
According to this I could just check caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave claims that this state will stay true even if the tracepoint is disabled. Is there anything else I should check for?

I would recommend doing this in the UST probe provider instead. Within the TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, you could parse the format string there in the last argument of a ctf_string() (a statement expression). The format string would be received as parameter by the tracepoint, along with a variable arg list (...). In the probe, it would be turned into a va_list (see stdarg(3)), and the parameters could be decoded into a string there. This has the benefit of moving the serialization call out-of-line into the probe provider rather than clobbering the tracepoint call site.

Thoughts ?

Thanks,

Mathieu

Thanks,
Mate

From: Máté Ferenczy
Sent: Wednesday, December 11, 2013 12:17 PM
To: 'mathieu.desnoyers@efficios.com'
Cc: 'lttng-dev@lists.lttng.org'
Subject: efficient use of LTTng in legacy codebase
Hello Mathieu,
Our team was asked to support LTTng UST solution in a legacy codebase. The existing codebase is fairly large, and the requirement is that we provide all the existing logs and debugs in the system as LTTng traces.
The planned solution so far was just to pass everything we have as text (strings) to LTTng. For that we obviously have to convert the printf-like format string and parameter list to a string by calling snprintf before giving the string to the LTTng API. That would however mean, that these snprintfs are getting called every time even if there is no listener/active trace session for the given trace. In this case, all those unnecessary snprintf calls may end up significantly impacting the performance of our applications.
In order to work around this, we were thinking that if there was a way to query the LTTng library from our application code whether there is an active tracing session for the given trace level, we could avoid calling those snprintfs in case they are not needed. Do you think it would be feasible to easily get this data from LTTng lib? If yes, can you provide us some pointers where to look at in order to do those changes ourselves?
Any suggestions are welcome.
Thank you,
Mate Ferenczy


--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com


--
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

[-- Attachment #1.2: Type: text/html, Size: 21469 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
       [not found]       ` <ECCC3645D4115E4293D3E8C0EB22F09C233310@ESESSMB109.ericsson.se>
@ 2014-01-15  8:03         ` Amit Margalit
  0 siblings, 0 replies; 12+ messages in thread
From: Amit Margalit @ 2014-01-15  8:03 UTC (permalink / raw)
  To: Máté Ferenczy; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 6152 bytes --]

As before, I still prefer a more sophisticated approach, that stores the 
format string in the metadata...

Amit Margalit
IBM XIV - Storage Reinvented
XIV-NAS Development Team
Tel. 03-689-7774
Fax. 03-689-7230



From:   Máté Ferenczy <mate.ferenczy@ericsson.com>
To:     Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Cc:     "lttng-dev@lists.lttng.org" <lttng-dev@lists.lttng.org>
Date:   01/14/2014 08:10 PM
Subject:        Re: [lttng-dev] efficient use of LTTng in legacy codebase



After some discussion, the following solution seems to be simpler and not 
dependent on LTTng UST internals:
 
#define tracepoint_for_format_string(provider, name, ?) \
      do { \
            char msg_buf[MAX_BUFFER_SIZE]; \
            tracepoint(provider, name, my_snprintf(msg_buf, 
MAX_BUFFER_SIZE, __VA_ARGS__)); \
      } while (0)
 
my_snprintf should return the pointer to the msg_buf. Although this 
solution allocates the buffer on the stack even if the tracepoint is 
disabled, this should be a very fast operation, and as long as the buffer 
size is much smaller than the maximum stack size should be ok. Another 
option is to allocate memory inside the my_snprintf function by malloc, 
which would only be called if the tracepoint is enabled, however in those 
cases the memory allocation would be more expensive.
 
We would probably prefer this solution compared to the attached patch, as 
it is independent of LTTng implementation.
 
Any comments, suggestions are appreciated.
 
Thanks,
mate
 
From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com] 
Sent: Thursday, December 12, 2013 4:35 AM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org
Subject: Re: efficient use of LTTng in legacy codebase
 
Just to speed things up, please have a look at the proposed UST patch. 
(it's not in mainline yet)
 
This is specifically for a demo program example so far.
 
Comments are welcome,
 
Thanks,
 
Mathieu
 
 

From: "Máté Ferenczy" <mate.ferenczy@ericsson.com>
To: "Mathieu Desnoyers" <mathieu.desnoyers@efficios.com>
Cc: lttng-dev@lists.lttng.org
Sent: Wednesday, December 11, 2013 8:52:30 PM
Subject: RE: efficient use of LTTng in legacy codebase
 
It sounds great, I like the idea. Just to make sure I understand your 
suggestion, are we talking about converting the variable argument list to 
string in include/lttng/ust-tracepoint-event-write.h?
 
For example:
#define ctf_format_string(_item, ?)                               \
        do {                                                      \
            char _buf[BUF_MAXLEN];                               \
            snprintf(buf, sizeof(_buf), __VA_ARGS__);            \
            _ctf_string(_item, _buf, 0);                         \
       } while(0)
 
Or do you have some better place to put this logic?
 
Thanks,
Mate
 
From: Mathieu Desnoyers [mailto:mathieu.desnoyers@efficios.com] 
Sent: Wednesday, December 11, 2013 4:48 PM
To: Máté Ferenczy
Cc: lttng-dev@lists.lttng.org
Subject: Re: efficient use of LTTng in legacy codebase
 

From: "Máté Ferenczy" <mate.ferenczy@ericsson.com>
To: "mathieu desnoyers" <mathieu.desnoyers@efficios.com>
Cc: lttng-dev@lists.lttng.org
Sent: Wednesday, December 11, 2013 6:52:22 PM
Subject: RE: efficient use of LTTng in legacy codebase
 
I found this email thread: 
https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html
According to this I could just check 
caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave 
claims that this state will stay true even if the tracepoint is disabled. 
Is there anything else I should check for?
 
I would recommend doing this in the UST probe provider instead. Within the 
TRACEPOINT_EVENT "TP_FIELD" section, when you declare your string field, 
you could parse the format string there in the last argument of a 
ctf_string() (a statement expression). The format string would be received 
as parameter by the tracepoint, along with a variable arg list (...). In 
the probe, it would be turned into a va_list (see stdarg(3)), and the 
parameters could be decoded into a string there. This has the benefit of 
moving the serialization call out-of-line into the probe provider rather 
than clobbering the tracepoint call site.
 
Thoughts ?
 
Thanks,
 
Mathieu
 
Thanks,
Mate
 
From: Máté Ferenczy 
Sent: Wednesday, December 11, 2013 12:17 PM
To: 'mathieu.desnoyers@efficios.com'
Cc: 'lttng-dev@lists.lttng.org'
Subject: efficient use of LTTng in legacy codebase
Hello Mathieu,
Our team was asked to support LTTng UST solution in a legacy codebase. The 
existing codebase is fairly large, and the requirement is that we provide 
all the existing logs and debugs in the system as LTTng traces.
The planned solution so far was just to pass everything we have as text 
(strings) to LTTng. For that we obviously have to convert the printf-like 
format string and parameter list to a string by calling snprintf before 
giving the string to the LTTng API. That would however mean, that these 
snprintfs are getting called every time even if there is no 
listener/active trace session for the given trace. In this case, all those 
unnecessary snprintf calls may end up significantly impacting the 
performance of our applications.
In order to work around this, we were thinking that if there was a way to 
query the LTTng library from our application code whether there is an 
active tracing session for the given trace level, we could avoid calling 
those snprintfs in case they are not needed. Do you think it would be 
feasible to easily get this data from LTTng lib? If yes, can you provide 
us some pointers where to look at in order to do those changes ourselves?
Any suggestions are welcome.
Thank you,
Mate Ferenczy
 
 
-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com
 
 
-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev


[-- Attachment #1.2: Type: text/html, Size: 13613 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* Re: efficient use of LTTng in legacy codebase
@ 2013-12-11 23:52 Máté Ferenczy
  0 siblings, 0 replies; 12+ messages in thread
From: Máté Ferenczy @ 2013-12-11 23:52 UTC (permalink / raw)
  To: mathieu.desnoyers; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 1791 bytes --]

I found this email thread: https://www.mail-archive.com/lttng-dev@lists.lttng.org/msg02278.html

According to this I could just check caa_unlikely(__tracepoint_##provider##___##name.state). However, Dave claims that this state will stay true even if the tracepoint is disabled. Is there anything else I should check for?

Thanks,
Mate

From: Máté Ferenczy
Sent: Wednesday, December 11, 2013 12:17 PM
To: 'mathieu.desnoyers@efficios.com'
Cc: 'lttng-dev@lists.lttng.org'
Subject: efficient use of LTTng in legacy codebase

Hello Mathieu,

Our team was asked to support LTTng UST solution in a legacy codebase. The existing codebase is fairly large, and the requirement is that we provide all the existing logs and debugs in the system as LTTng traces.

The planned solution so far was just to pass everything we have as text (strings) to LTTng. For that we obviously have to convert the printf-like format string and parameter list to a string by calling snprintf before giving the string to the LTTng API. That would however mean, that these snprintfs are getting called every time even if there is no listener/active trace session for the given trace. In this case, all those unnecessary snprintf calls may end up significantly impacting the performance of our applications.

In order to work around this, we were thinking that if there was a way to query the LTTng library from our application code whether there is an active tracing session for the given trace level, we could avoid calling those snprintfs in case they are not needed. Do you think it would be feasible to easily get this data from LTTng lib? If yes, can you provide us some pointers where to look at in order to do those changes ourselves?

Any suggestions are welcome.

Thank you,
Mate Ferenczy

[-- Attachment #1.2: Type: text/html, Size: 4796 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

* efficient use of LTTng in legacy codebase
@ 2013-12-11 20:17 Máté Ferenczy
  0 siblings, 0 replies; 12+ messages in thread
From: Máté Ferenczy @ 2013-12-11 20:17 UTC (permalink / raw)
  To: mathieu.desnoyers; +Cc: lttng-dev


[-- Attachment #1.1: Type: text/plain, Size: 1257 bytes --]

Hello Mathieu,

Our team was asked to support LTTng UST solution in a legacy codebase. The existing codebase is fairly large, and the requirement is that we provide all the existing logs and debugs in the system as LTTng traces.

The planned solution so far was just to pass everything we have as text (strings) to LTTng. For that we obviously have to convert the printf-like format string and parameter list to a string by calling snprintf before giving the string to the LTTng API. That would however mean, that these snprintfs are getting called every time even if there is no listener/active trace session for the given trace. In this case, all those unnecessary snprintf calls may end up significantly impacting the performance of our applications.

In order to work around this, we were thinking that if there was a way to query the LTTng library from our application code whether there is an active tracing session for the given trace level, we could avoid calling those snprintfs in case they are not needed. Do you think it would be feasible to easily get this data from LTTng lib? If yes, can you provide us some pointers where to look at in order to do those changes ourselves?

Any suggestions are welcome.

Thank you,
Mate Ferenczy

[-- Attachment #1.2: Type: text/html, Size: 3263 bytes --]

[-- Attachment #2: Type: text/plain, Size: 155 bytes --]

_______________________________________________
lttng-dev mailing list
lttng-dev@lists.lttng.org
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev

^ permalink raw reply	[flat|nested] 12+ messages in thread

end of thread, other threads:[~2014-01-15  8:03 UTC | newest]

Thread overview: 12+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
     [not found] <ECCC3645D4115E4293D3E8C0EB22F09C20D363@ESESSMB109.ericsson.se>
2013-12-12  0:47 ` efficient use of LTTng in legacy codebase Mathieu Desnoyers
     [not found] ` <38714154.84070.1386809251111.JavaMail.zimbra@efficios.com>
2013-12-12  1:52   ` Máté Ferenczy
     [not found]   ` <ECCC3645D4115E4293D3E8C0EB22F09C20D3F6@ESESSMB109.ericsson.se>
2013-12-12 12:35     ` Mathieu Desnoyers
     [not found]     ` <1206710241.84238.1386851719338.JavaMail.zimbra@efficios.com>
2013-12-12 17:30       ` Máté Ferenczy
     [not found]       ` <ECCC3645D4115E4293D3E8C0EB22F09C20D572@ESESSMB109.ericsson.se>
2013-12-15 12:56         ` Amit Margalit
     [not found]         ` <OFA420391C.226AC243-ONC2257C42.00460223-C2257C42.00471974@il.ibm.com>
2013-12-16  1:11           ` Máté Ferenczy
     [not found]           ` <ECCC3645D4115E4293D3E8C0EB22F09C22CC8E@ESESSMB109.ericsson.se>
2013-12-17  7:35             ` Amit Margalit
     [not found]             ` <OF7A09BD18.DB100453-ONC2257C44.0025741C-C2257C44.0029B7A4@il.ibm.com>
2013-12-17 20:36               ` Máté Ferenczy
2013-12-19  3:31       ` Máté Ferenczy
     [not found]       ` <ECCC3645D4115E4293D3E8C0EB22F09C233310@ESESSMB109.ericsson.se>
2014-01-15  8:03         ` Amit Margalit
2013-12-11 23:52 Máté Ferenczy
  -- strict thread matches above, loose matches on Subject: below --
2013-12-11 20:17 Máté Ferenczy

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.