Merge pull request #7194 from qlyoung/tracing

Tracing
This commit is contained in:
Mark Stapp 2020-10-24 16:50:35 -04:00 committed by GitHub
commit cbd492990d
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
21 changed files with 980 additions and 21 deletions

View file

@ -39,6 +39,7 @@
#include "bgpd/bgp_errors.h" // for expanded error reference information
#include "bgpd/bgp_fsm.h" // for BGP_EVENT_ADD, bgp_event
#include "bgpd/bgp_packet.h" // for bgp_notify_send_with_data, bgp_notify...
#include "bgpd/bgp_trace.h" // for frrtraces
#include "bgpd/bgpd.h" // for peer, BGP_MARKER_SIZE, bgp_master, bm
/* clang-format on */
@ -234,6 +235,7 @@ static int bgp_process_reads(struct thread *thread)
assert(ringbuf_get(ibw, pkt->data, pktsize) == pktsize);
stream_set_endp(pkt, pktsize);
frrtrace(2, frr_bgp, packet_read, peer, pkt);
frr_with_mutex(&peer->io_mtx) {
stream_fifo_push(peer->ibuf, pkt);
}

View file

@ -63,6 +63,7 @@
#include "bgpd/bgp_io.h"
#include "bgpd/bgp_keepalives.h"
#include "bgpd/bgp_flowspec.h"
#include "bgpd/bgp_trace.h"
DEFINE_HOOK(bgp_packet_dump,
(struct peer *peer, uint8_t type, bgp_size_t size,
@ -2366,6 +2367,7 @@ int bgp_process_packet(struct thread *thread)
*/
switch (type) {
case BGP_MSG_OPEN:
frrtrace(2, frr_bgp, open_process, peer, size);
atomic_fetch_add_explicit(&peer->open_in, 1,
memory_order_relaxed);
mprc = bgp_open_receive(peer, size);
@ -2376,6 +2378,7 @@ int bgp_process_packet(struct thread *thread)
__func__, peer->host);
break;
case BGP_MSG_UPDATE:
frrtrace(2, frr_bgp, update_process, peer, size);
atomic_fetch_add_explicit(&peer->update_in, 1,
memory_order_relaxed);
peer->readtime = monotime(NULL);
@ -2387,6 +2390,7 @@ int bgp_process_packet(struct thread *thread)
__func__, peer->host);
break;
case BGP_MSG_NOTIFY:
frrtrace(2, frr_bgp, notification_process, peer, size);
atomic_fetch_add_explicit(&peer->notify_in, 1,
memory_order_relaxed);
mprc = bgp_notify_receive(peer, size);
@ -2397,6 +2401,7 @@ int bgp_process_packet(struct thread *thread)
__func__, peer->host);
break;
case BGP_MSG_KEEPALIVE:
frrtrace(2, frr_bgp, keepalive_process, peer, size);
peer->readtime = monotime(NULL);
atomic_fetch_add_explicit(&peer->keepalive_in, 1,
memory_order_relaxed);
@ -2409,6 +2414,7 @@ int bgp_process_packet(struct thread *thread)
break;
case BGP_MSG_ROUTE_REFRESH_NEW:
case BGP_MSG_ROUTE_REFRESH_OLD:
frrtrace(2, frr_bgp, refresh_process, peer, size);
atomic_fetch_add_explicit(&peer->refresh_in, 1,
memory_order_relaxed);
mprc = bgp_route_refresh_receive(peer, size);
@ -2419,6 +2425,7 @@ int bgp_process_packet(struct thread *thread)
__func__, peer->host);
break;
case BGP_MSG_CAPABILITY:
frrtrace(2, frr_bgp, capability_process, peer, size);
atomic_fetch_add_explicit(&peer->dynamic_cap_in, 1,
memory_order_relaxed);
mprc = bgp_capability_receive(peer, size);

View file

@ -70,6 +70,7 @@
#include "bgpd/bgp_addpath.h"
#include "bgpd/bgp_mac.h"
#include "bgpd/bgp_network.h"
#include "bgpd/bgp_trace.h"
#ifdef ENABLE_BGP_VNC
#include "bgpd/rfapi/rfapi_backend.h"
@ -1296,6 +1297,7 @@ static enum filter_type bgp_input_filter(struct peer *peer,
safi_t safi)
{
struct bgp_filter *filter;
enum filter_type ret = FILTER_PERMIT;
filter = &peer->filter[afi][safi];
@ -1307,26 +1309,43 @@ static enum filter_type bgp_input_filter(struct peer *peer,
if (DISTRIBUTE_IN_NAME(filter)) {
FILTER_EXIST_WARN(DISTRIBUTE, distribute, filter);
if (access_list_apply(DISTRIBUTE_IN(filter), p) == FILTER_DENY)
return FILTER_DENY;
if (access_list_apply(DISTRIBUTE_IN(filter), p)
== FILTER_DENY) {
ret = FILTER_DENY;
goto done;
}
}
if (PREFIX_LIST_IN_NAME(filter)) {
FILTER_EXIST_WARN(PREFIX_LIST, prefix, filter);
if (prefix_list_apply(PREFIX_LIST_IN(filter), p) == PREFIX_DENY)
return FILTER_DENY;
if (prefix_list_apply(PREFIX_LIST_IN(filter), p)
== PREFIX_DENY) {
ret = FILTER_DENY;
goto done;
}
}
if (FILTER_LIST_IN_NAME(filter)) {
FILTER_EXIST_WARN(FILTER_LIST, as, filter);
if (as_list_apply(FILTER_LIST_IN(filter), attr->aspath)
== AS_FILTER_DENY)
return FILTER_DENY;
== AS_FILTER_DENY) {
ret = FILTER_DENY;
goto done;
}
}
return FILTER_PERMIT;
done:
if (frrtrace_enabled(frr_bgp, input_filter)) {
char pfxprint[PREFIX2STR_BUFFER];
prefix2str(p, pfxprint, sizeof(pfxprint));
frrtrace(5, frr_bgp, input_filter, peer, pfxprint, afi, safi,
ret == FILTER_PERMIT ? "permit" : "deny");
}
return ret;
#undef FILTER_EXIST_WARN
}
@ -1336,6 +1355,7 @@ static enum filter_type bgp_output_filter(struct peer *peer,
safi_t safi)
{
struct bgp_filter *filter;
enum filter_type ret = FILTER_PERMIT;
filter = &peer->filter[afi][safi];
@ -1347,27 +1367,43 @@ static enum filter_type bgp_output_filter(struct peer *peer,
if (DISTRIBUTE_OUT_NAME(filter)) {
FILTER_EXIST_WARN(DISTRIBUTE, distribute, filter);
if (access_list_apply(DISTRIBUTE_OUT(filter), p) == FILTER_DENY)
return FILTER_DENY;
if (access_list_apply(DISTRIBUTE_OUT(filter), p)
== FILTER_DENY) {
ret = FILTER_DENY;
goto done;
}
}
if (PREFIX_LIST_OUT_NAME(filter)) {
FILTER_EXIST_WARN(PREFIX_LIST, prefix, filter);
if (prefix_list_apply(PREFIX_LIST_OUT(filter), p)
== PREFIX_DENY)
return FILTER_DENY;
== PREFIX_DENY) {
ret = FILTER_DENY;
goto done;
}
}
if (FILTER_LIST_OUT_NAME(filter)) {
FILTER_EXIST_WARN(FILTER_LIST, as, filter);
if (as_list_apply(FILTER_LIST_OUT(filter), attr->aspath)
== AS_FILTER_DENY)
return FILTER_DENY;
== AS_FILTER_DENY) {
ret = FILTER_DENY;
goto done;
}
}
return FILTER_PERMIT;
if (frrtrace_enabled(frr_bgp, output_filter)) {
char pfxprint[PREFIX2STR_BUFFER];
prefix2str(p, pfxprint, sizeof(pfxprint));
frrtrace(5, frr_bgp, output_filter, peer, pfxprint, afi, safi,
ret == FILTER_PERMIT ? "permit" : "deny");
}
done:
return ret;
#undef FILTER_EXIST_WARN
}
@ -3432,6 +3468,14 @@ int bgp_update(struct peer *peer, const struct prefix *p, uint32_t addpath_id,
uint8_t pi_type = 0;
uint8_t pi_sub_type = 0;
if (frrtrace_enabled(frr_bgp, process_update)) {
char pfxprint[PREFIX2STR_BUFFER];
prefix2str(p, pfxprint, sizeof(pfxprint));
frrtrace(6, frr_bgp, process_update, peer, pfxprint, addpath_id,
afi, safi, attr);
}
#ifdef ENABLE_BGP_VNC
int vnc_implicit_withdraw = 0;
#endif

4
bgpd/bgp_trace.c Normal file
View file

@ -0,0 +1,4 @@
#define TRACEPOINT_CREATE_PROBES
#define TRACEPOINT_DEFINE
#include "bgp_trace.h"

131
bgpd/bgp_trace.h Normal file
View file

@ -0,0 +1,131 @@
/* Tracing for BGP
*
* Copyright (C) 2020 NVIDIA Corporation
* Quentin Young
*
* This program is free software; you can redistribute it and/or modify it
* under the terms of the GNU General Public License as published by the Free
* Software Foundation; either version 2 of the License, or (at your option)
* any later version.
*
* This program 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 General Public License for
* more details.
*
* You should have received a copy of the GNU General Public License along
* with this program; see the file COPYING; if not, write to the Free Software
* Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA
*/
#if !defined(_BGP_TRACE_H) || defined(TRACEPOINT_HEADER_MULTI_READ)
#define _BGP_TRACE_H
#include "lib/trace.h"
#ifdef HAVE_LTTNG
#undef TRACEPOINT_PROVIDER
#define TRACEPOINT_PROVIDER frr_bgp
#undef TRACEPOINT_INCLUDE
#define TRACEPOINT_INCLUDE "bgpd/bgp_trace.h"
#include <lttng/tracepoint.h>
#include "bgpd/bgpd.h"
#include "lib/stream.h"
/* clang-format off */
TRACEPOINT_EVENT_CLASS(
frr_bgp,
packet_process,
TP_ARGS(struct peer *, peer, bgp_size_t, size),
TP_FIELDS(
ctf_string(peer, peer->host ? peer->host : "(unknown peer)")
)
)
#define PKT_PROCESS_TRACEPOINT_INSTANCE(name) \
TRACEPOINT_EVENT_INSTANCE( \
frr_bgp, packet_process, name, \
TP_ARGS(struct peer *, peer, bgp_size_t, size)) \
TRACEPOINT_LOGLEVEL(frr_bgp, name, TRACE_INFO)
PKT_PROCESS_TRACEPOINT_INSTANCE(open_process)
PKT_PROCESS_TRACEPOINT_INSTANCE(keepalive_process)
PKT_PROCESS_TRACEPOINT_INSTANCE(update_process)
PKT_PROCESS_TRACEPOINT_INSTANCE(notification_process)
PKT_PROCESS_TRACEPOINT_INSTANCE(capability_process)
PKT_PROCESS_TRACEPOINT_INSTANCE(refresh_process)
TRACEPOINT_EVENT(
frr_bgp,
packet_read,
TP_ARGS(struct peer *, peer, struct stream *, pkt),
TP_FIELDS(
ctf_string(peer, peer->host ? peer->host : "(unknown peer)")
ctf_sequence_hex(uint8_t, packet, pkt->data, size_t,
STREAM_READABLE(pkt))
)
)
TRACEPOINT_LOGLEVEL(frr_bgp, packet_read, TRACE_INFO)
TRACEPOINT_EVENT(
frr_bgp,
process_update,
TP_ARGS(struct peer *, peer, char *, pfx, uint32_t, addpath_id, afi_t,
afi, safi_t, safi, struct attr *, attr),
TP_FIELDS(
ctf_string(peer, peer->host ? peer->host : "(unknown peer)")
ctf_string(prefix, pfx)
ctf_integer(uint32_t, addpath_id, addpath_id)
ctf_integer(afi_t, afi, afi)
ctf_integer(safi_t, safi, safi)
ctf_integer_hex(intptr_t, attribute_ptr, attr)
)
)
TRACEPOINT_LOGLEVEL(frr_bgp, process_update, TRACE_INFO)
TRACEPOINT_EVENT(
frr_bgp,
input_filter,
TP_ARGS(struct peer *, peer, char *, pfx, afi_t, afi, safi_t, safi,
const char *, result),
TP_FIELDS(
ctf_string(peer, peer->host ? peer->host : "(unknown peer)")
ctf_string(prefix, pfx)
ctf_integer(afi_t, afi, afi)
ctf_integer(safi_t, safi, safi)
ctf_string(action, result)
)
)
TRACEPOINT_LOGLEVEL(frr_bgp, input_filter, TRACE_INFO)
TRACEPOINT_EVENT(
frr_bgp,
output_filter,
TP_ARGS(struct peer *, peer, char *, pfx, afi_t, afi, safi_t, safi,
const char *, result),
TP_FIELDS(
ctf_string(peer, peer->host ? peer->host : "(unknown peer)")
ctf_string(prefix, pfx)
ctf_integer(afi_t, afi, afi)
ctf_integer(safi_t, safi, safi)
ctf_string(action, result)
)
)
TRACEPOINT_LOGLEVEL(frr_bgp, output_filter, TRACE_INFO)
/* clang-format on */
#include <lttng/tracepoint-event.h>
#endif /* HAVE_LTTNG */
#endif /* _BGP_TRACE_H */

View file

@ -104,6 +104,7 @@ bgpd_libbgp_a_SOURCES = \
bgpd/bgpd.c \
bgpd/bgp_nb.c \
bgpd/bgp_nb_config.c \
bgpd/bgp_trace.c \
# end
if ENABLE_BGP_VNC
@ -178,6 +179,7 @@ noinst_HEADERS += \
bgpd/bgp_zebra.h \
bgpd/bgpd.h \
bgpd/bgp_nb.h \
bgpd/bgp_trace.h \
\
bgpd/rfapi/bgp_rfapi_cfg.h \
bgpd/rfapi/rfapi_import.h \
@ -208,8 +210,8 @@ bgpd_bgpd_CFLAGS = $(AM_CFLAGS)
bgpd_bgp_btoa_CFLAGS = $(AM_CFLAGS)
# RFPLDADD is set in bgpd/rfp-example/librfp/subdir.am
bgpd_bgpd_LDADD = bgpd/libbgp.a $(RFPLDADD) lib/libfrr.la $(LIBCAP) $(LIBM)
bgpd_bgp_btoa_LDADD = bgpd/libbgp.a $(RFPLDADD) lib/libfrr.la $(LIBCAP) $(LIBM)
bgpd_bgpd_LDADD = bgpd/libbgp.a $(RFPLDADD) lib/libfrr.la $(LIBCAP) $(LIBM) $(UST_LIBS)
bgpd_bgp_btoa_LDADD = bgpd/libbgp.a $(RFPLDADD) lib/libfrr.la $(LIBCAP) $(LIBM) $(UST_LIBS)
bgpd_bgpd_snmp_la_SOURCES = bgpd/bgp_snmp.c
bgpd_bgpd_snmp_la_CFLAGS = $(WERROR) $(SNMP_CFLAGS) -std=gnu99

View file

@ -566,6 +566,10 @@ AC_ARG_ENABLE([grpc],
AS_HELP_STRING([--enable-grpc], [enable the gRPC northbound plugin]))
AC_ARG_ENABLE([zeromq],
AS_HELP_STRING([--enable-zeromq], [enable ZeroMQ handler (libfrrzmq)]))
AC_ARG_ENABLE([lttng],
AS_HELP_STRING([--enable-lttng], [enable LTTng tracing]))
AC_ARG_ENABLE([usdt],
AS_HELP_STRING([--enable-usdt], [enable USDT probes]))
AC_ARG_WITH([libpam],
AS_HELP_STRING([--with-libpam], [use libpam for PAM support in vtysh]))
AC_ARG_ENABLE([ospfapi],
@ -1851,6 +1855,30 @@ if test "$enable_grpc" = "yes"; then
])
fi
dnl -----
dnl LTTng
dnl -----
if test "$enable_lttng" = "yes"; then
PKG_CHECK_MODULES([UST], [lttng-ust >= 2.12.0], [
AC_DEFINE([HAVE_LTTNG], [1], [Enable LTTng support])
LTTNG=true
], [
AC_MSG_ERROR([configuration specifies --enable-lttng but lttng-ust was not found])
])
fi
dnl ----
dnl USDT
dnl ----
if test "$enable_usdt" = "yes"; then
AC_CHECK_HEADERS([sys/sdt.h], [
AC_DEFINE([HAVE_USDT], [1], [Enable USDT probes])
USDT=true
], [
AC_MSG_ERROR([configuration specifies --enable-usdt but no USDT kernel headers (sys/sdt.h) found])
])
fi
dnl ------
dnl ZeroMQ
dnl ------

View file

@ -9,6 +9,7 @@ FRRouting Developer's Guide
packaging
process-architecture
library
tracing
testing
bgpd
fpm

314
doc/developer/tracing.rst Normal file
View file

@ -0,0 +1,314 @@
.. _tracing:
Tracing
=======
FRR has a small but growing number of static tracepoints available for use with
various tracing systems. These tracepoints can assist with debugging,
performance analysis and to help understand program flow. They can also be used
for monitoring.
Developers are encouraged to write new static tracepoints where sensible. They
are not compiled in by default, and even when they are, they have no overhead
unless enabled by a tracer, so it is okay to be liberal with them.
Supported tracers
-----------------
Presently two types of tracepoints are supported:
- `LTTng tracepoints <https://lttng.org/>`_
- `USDT probes <http://dtrace.org/guide/chp-usdt.html>`_
LTTng is a tracing framework for Linux only. It offers extremely low overhead
and very rich tracing capabilities. FRR supports LTTng-UST, which is the
userspace implementation. LTTng tracepoints are very rich in detail. No kernel
modules are needed. Besides only being available for Linux, the primary
downside of LTTng is the need to link to ``lttng-ust``.
USDT probes originate from Solaris, where they were invented for use with
dtrace. They are a kernel feature. At least Linux and FreeBSD support them. No
library is needed; support is compiled in via a system header
(``<sys/sdt.h>``). USDT probes are much slower than LTTng tracepoints and offer
less flexibility in what information can be gleaned from them.
LTTng is capable of tracing USDT probes but has limited support for them.
SystemTap and dtrace both work only with USDT probes.
Usage
-----
To compile with tracepoints, use one of the following configure flags:
.. program:: configure.ac
.. option:: --enable-lttng=yes
Generate LTTng tracepoints
.. option:: --enable-usdt=yes
Generate USDT probes
To trace with LTTng, compile with either one (prefer :option:`--enable-lttng`
run the target in non-forking mode (no ``-d``) and use LTTng as usual (refer to
LTTng user manual). When using USDT probes with LTTng, follow the example in
`this article
<https://lttng.org/blog/2019/10/15/new-dynamic-user-space-tracing-in-lttng/>`_.
To trace with dtrace or SystemTap, compile with :option:`--enable-usdt=yes` and
use your tracer as usual.
To see available USDT probes::
readelf -n /usr/lib/frr/bgpd
Example::
root@host ~> readelf -n /usr/lib/frr/bgpd
Displaying notes found in: .note.ABI-tag
Owner Data size Description
GNU 0x00000010 NT_GNU_ABI_TAG (ABI version tag)
OS: Linux, ABI: 3.2.0
Displaying notes found in: .note.gnu.build-id
Owner Data size Description
GNU 0x00000014 NT_GNU_BUILD_ID (unique build ID bitstring)
Build ID: 4f42933a69dcb42a519bc459b2105177c8adf55d
Displaying notes found in: .note.stapsdt
Owner Data size Description
stapsdt 0x00000045 NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: packet_read
Location: 0x000000000045ee48, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-96(%rbp) 8@-104(%rbp)
stapsdt 0x00000047 NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: open_process
Location: 0x000000000047c43b, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-224(%rbp) 2@-226(%rbp)
stapsdt 0x00000049 NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: update_process
Location: 0x000000000047c4bf, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-208(%rbp) 2@-210(%rbp)
stapsdt 0x0000004f NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: notification_process
Location: 0x000000000047c557, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-192(%rbp) 2@-194(%rbp)
stapsdt 0x0000004c NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: keepalive_process
Location: 0x000000000047c5db, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-176(%rbp) 2@-178(%rbp)
stapsdt 0x0000004a NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: refresh_process
Location: 0x000000000047c673, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-160(%rbp) 2@-162(%rbp)
stapsdt 0x0000004d NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: capability_process
Location: 0x000000000047c6f7, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-144(%rbp) 2@-146(%rbp)
stapsdt 0x0000006f NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: output_filter
Location: 0x000000000048e33a, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-144(%rbp) 8@-152(%rbp) 4@-156(%rbp) 4@-160(%rbp) 8@-168(%rbp)
stapsdt 0x0000007d NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: process_update
Location: 0x0000000000491f10, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-800(%rbp) 8@-808(%rbp) 4@-812(%rbp) 4@-816(%rbp) 4@-820(%rbp) 8@-832(%rbp)
stapsdt 0x0000006e NT_STAPSDT (SystemTap probe descriptors)
Provider: frr_bgp
Name: input_filter
Location: 0x00000000004940ed, Base: 0x00000000005a09d2, Semaphore: 0x0000000000000000
Arguments: 8@-144(%rbp) 8@-152(%rbp) 4@-156(%rbp) 4@-160(%rbp) 8@-168(%rbp)
To see available LTTng probes, run the target, create a session and then::
lttng list --userspace | grep frr
Example::
root@host ~> lttng list --userspace | grep frr
PID: 11157 - Name: /usr/lib/frr/bgpd
frr_libfrr:route_node_get (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
frr_libfrr:list_sort (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
frr_libfrr:list_delete_node (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
frr_libfrr:list_remove (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
frr_libfrr:list_add (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
frr_libfrr:memfree (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
frr_libfrr:memalloc (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
frr_libfrr:frr_pthread_stop (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
frr_libfrr:frr_pthread_run (loglevel: TRACE_DEBUG_LINE (13)) (type: tracepoint)
frr_libfrr:thread_call (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_libfrr:thread_cancel_async (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_libfrr:thread_cancel (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_libfrr:schedule_write (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_libfrr:schedule_read (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_libfrr:schedule_event (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_libfrr:schedule_timer (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_libfrr:hash_release (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_libfrr:hash_insert (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_libfrr:hash_get (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:output_filter (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:input_filter (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:process_update (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:packet_read (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:refresh_process (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:capability_process (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:notification_process (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:update_process (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:keepalive_process (loglevel: TRACE_INFO (6)) (type: tracepoint)
frr_bgp:open_process (loglevel: TRACE_INFO (6)) (type: tracepoint)
When using LTTng, you can also get zlogs as trace events by enabling
the ``lttng_ust_tracelog:*`` event class.
Concepts
--------
Tracepoints are statically defined points in code where a developer has
determined that outside observers might gain something from knowing what is
going on at that point. It's like logging but with the ability to dump large
amounts of internal data with much higher performance. LTTng has a good summary
`here <https://lttng.org/docs/#doc-what-is-tracing>`_.
Each tracepoint has a "provider" and name. The provider is basically a
namespace; for example, ``bgpd`` uses the provider name ``frr_bgp``. The name
is arbitrary, but because providers share a global namespace on the user's
system, all providers from FRR should be prefixed by ``frr_``. The tracepoint
name is just the name of the event. Events are globally named by their provider
and name. For example, the event when BGP reads a packet from a peer is
``frr_bgp:packet_read``.
To do tracing, the tracing tool of choice is told which events to listen to.
For example, to listen to all events from FRR's BGP implementation, you would
enable the events ``frr_bgp:*``. In the same tracing session you could also
choose to record all memory allocations by enabling the ``malloc`` tracepoints
in ``libc`` as well as all kernel skb operations using the various in-kernel
tracepoints. This allows you to build as complete a view as desired of what the
system is doing during the tracing window (subject to what tracepoints are
available).
Of particular use are the tracepoints for FRR's internal event scheduler;
tracing these allows you to see all events executed by all event loops for the
target(s) in question. Here's a couple events selected from a trace of BGP
during startup::
...
[18:41:35.750131763] (+0.000048901) host frr_libfrr:thread_call: { cpu_id =
1 }, { threadmaster_name = "default", function_name = "zclient_connect",
scheduled_from = "lib/zclient.c", scheduled_on_line = 3877, thread_addr =
0x0, file_descriptor = 0, event_value = 0, argument_ptr = 0xA37F70, timer =
0 }
[18:41:35.750175124] (+0.000020001) host frr_libfrr:thread_call: { cpu_id =
1 }, { threadmaster_name = "default", function_name = "frr_config_read_in",
scheduled_from = "lib/libfrr.c", scheduled_on_line = 934, thread_addr = 0x0,
file_descriptor = 0, event_value = 0, argument_ptr = 0x0, timer = 0 }
[18:41:35.753341264] (+0.000010532) host frr_libfrr:thread_call: { cpu_id =
1 }, { threadmaster_name = "default", function_name = "bgp_event",
scheduled_from = "bgpd/bgpd.c", scheduled_on_line = 142, thread_addr = 0x0,
file_descriptor = 2, event_value = 2, argument_ptr = 0xE4D780, timer = 2 }
[18:41:35.753404186] (+0.000004910) host frr_libfrr:thread_call: { cpu_id =
1 }, { threadmaster_name = "default", function_name = "zclient_read",
scheduled_from = "lib/zclient.c", scheduled_on_line = 3891, thread_addr =
0x0, file_descriptor = 40, event_value = 40, argument_ptr = 0xA37F70, timer
= 40 }
...
Very useful for getting a time-ordered look into what the process is doing.
Adding Tracepoints
------------------
Adding new tracepoints is a two step process:
1. Define the tracepoint
2. Use the tracepoint
Tracepoint definitions state the "provider" and name of the tracepoint, along
with any values it will produce, and how to format them. This is done with
macros provided by LTTng. USDT probes do not use definitions and are inserted
at the trace site with a single macro. However, to maintain support for both
platforms, you must define an LTTng tracepoint when adding a new one.
``frrtrace()`` will expand to the appropriate ``DTRACE_PROBEn`` macro when USDT
is in use.
If you are adding new tracepoints to a daemon that has no tracepoints, that
daemon's ``subdir.am`` must be updated to conditionally link ``lttng-ust``.
Look at ``bgpd/subdir.am`` for an example of how to do this; grep for
``UST_LIBS``. Create new files named ``<daemon>_trace.[ch]``. Use
``bgpd/bgp_trace.[h]`` as boilerplate. If you are adding tracepoints to a
daemon that already has them, look for the ``<daemon>_trace.h`` file;
tracepoints are written here.
Refer to the `LTTng developer docs
<https://lttng.org/docs/#doc-c-application>`_ for details on how to define
tracepoints.
To use them, simply add a call to ``frrtrace()`` at the point you'd like the
event to be emitted, like so:
.. code-block:: c
...
switch (type) {
case BGP_MSG_OPEN:
frrtrace(2, frr_bgp, open_process, peer, size); /* tracepoint */
atomic_fetch_add_explicit(&peer->open_in, 1,
memory_order_relaxed);
mprc = bgp_open_receive(peer, size);
...
After recompiling this tracepoint will now be available, either as a USDT probe
or LTTng tracepoint, depending on your compilation choice.
trace.h
^^^^^^^
Because FRR supports multiple types of tracepoints, the code for creating them
abstracts away the underlying system being used. This abstraction code is in
``lib/trace.h``. There are 2 function-like macros that are used for working
with tracepoints.
- ``frrtrace()`` defines tracepoints
- ``frrtrace_enabled()`` checks whether a tracepoint is enabled
There is also ``frrtracelog()``, which is used in zlog core code to make zlog
messages available as trace events to LTTng. This should not be used elsewhere.
There is additional documentation in the header. The key thing to note is that
you should never include ``trace.h`` in source where you plan to put
tracepoints; include the tracepoint definition header instead (e.g.
:file:`bgp_trace.h`).
Limitations
-----------
Tracers do not like ``fork()`` or ``dlopen()``. LTTng has some workarounds for
this involving interceptor libraries using ``LD_PRELOAD``.
USDT tracepoints are relatively high overhead and probably shouldn't be used
for "flight recorder" functionality, i.e. enabling and passively recording all
events for monitoring purposes. It's generally okay to use LTTng like this,
though.

View file

@ -28,6 +28,7 @@
#include "memory.h"
#include "linklist.h"
#include "zlog.h"
#include "libfrr_trace.h"
DEFINE_MTYPE_STATIC(LIB, FRR_PTHREAD, "FRR POSIX Thread")
DEFINE_MTYPE_STATIC(LIB, PTHREAD_PRIM, "POSIX sync primitives")
@ -167,6 +168,8 @@ int frr_pthread_run(struct frr_pthread *fpt, const pthread_attr_t *attr)
sigfillset(&blocksigs);
pthread_sigmask(SIG_BLOCK, &blocksigs, &oldsigs);
frrtrace(1, frr_libfrr, frr_pthread_run, fpt->name);
fpt->rcu_thread = rcu_thread_prepare();
ret = pthread_create(&fpt->thread, attr, frr_pthread_inner, fpt);
@ -204,6 +207,8 @@ void frr_pthread_notify_running(struct frr_pthread *fpt)
int frr_pthread_stop(struct frr_pthread *fpt, void **result)
{
frrtrace(1, frr_libfrr, frr_pthread_stop, fpt->name);
int ret = (*fpt->attr.stop)(fpt, result);
memset(&fpt->thread, 0x00, sizeof(fpt->thread));
return ret;

View file

@ -29,6 +29,7 @@
#include "command.h"
#include "libfrr.h"
#include "frr_pthread.h"
#include "libfrr_trace.h"
DEFINE_MTYPE_STATIC(LIB, HASH, "Hash")
DEFINE_MTYPE_STATIC(LIB, HASH_BACKET, "Hash Bucket")
@ -138,6 +139,8 @@ static void hash_expand(struct hash *hash)
void *hash_get(struct hash *hash, void *data, void *(*alloc_func)(void *))
{
frrtrace(2, frr_libfrr, hash_get, hash, data);
unsigned int key;
unsigned int index;
void *newdata;
@ -172,6 +175,8 @@ void *hash_get(struct hash *hash, void *data, void *(*alloc_func)(void *))
hash->index[index] = bucket;
hash->count++;
frrtrace(3, frr_libfrr, hash_insert, hash, data, key);
int oldlen = bucket->next ? bucket->next->len : 0;
int newlen = oldlen + 1;
@ -206,7 +211,7 @@ unsigned int string_hash_make(const char *str)
void *hash_release(struct hash *hash, void *data)
{
void *ret;
void *ret = NULL;
unsigned int key;
unsigned int index;
struct hash_bucket *bucket;
@ -236,11 +241,14 @@ void *hash_release(struct hash *hash, void *data)
ret = bucket->data;
XFREE(MTYPE_HASH_BACKET, bucket);
hash->count--;
return ret;
break;
}
pp = bucket;
}
return NULL;
frrtrace(3, frr_libfrr, hash_release, hash, data, ret);
return ret;
}
void hash_iterate(struct hash *hash, void (*func)(struct hash_bucket *, void *),

4
lib/libfrr_trace.c Normal file
View file

@ -0,0 +1,4 @@
#define TRACEPOINT_CREATE_PROBES
#define TRACEPOINT_DEFINE
#include "libfrr_trace.h"

240
lib/libfrr_trace.h Normal file
View file

@ -0,0 +1,240 @@
/* Tracing
*
* Copyright (C) 2020 NVIDIA Corporation
* Quentin Young
*
* This program is free software; you can redistribute it and/or modify it
* under the terms of the GNU General Public License as published by the Free
* Software Foundation; either version 2 of the License, or (at your option)
* any later version.
*
* This program 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 General Public License for
* more details.
*
* You should have received a copy of the GNU General Public License along
* with this program; see the file COPYING; if not, write to the Free Software
* Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA
*/
#if !defined(_LIBFRR_TRACE_H_) || defined(TRACEPOINT_HEADER_MULTI_READ)
#define _LIBFRR_TRACE_H_
#include "trace.h"
#ifdef HAVE_LTTNG
#undef TRACEPOINT_PROVIDER
#define TRACEPOINT_PROVIDER frr_libfrr
#undef TRACEPOINT_INCLUDE
#define TRACEPOINT_INCLUDE "./libfrr_trace.h"
#include <lttng/tracepoint.h>
#include "hash.h"
#include "thread.h"
#include "memory.h"
#include "linklist.h"
#include "table.h"
/* clang-format off */
TRACEPOINT_EVENT(
frr_libfrr,
hash_get,
TP_ARGS(struct hash *, hash, void *, data),
TP_FIELDS(
ctf_string(name, hash->name ? hash->name : "(unnamed)")
ctf_integer(unsigned int, index_size, hash->size)
ctf_integer(unsigned long, item_count, hash->count)
ctf_integer_hex(intptr_t, data_ptr, data)
)
)
TRACEPOINT_LOGLEVEL(frr_libfrr, hash_get, TRACE_INFO)
TRACEPOINT_EVENT(
frr_libfrr,
hash_insert,
TP_ARGS(struct hash *, hash, void *, data, unsigned int, key),
TP_FIELDS(
ctf_string(name, hash->name ? hash->name : "(unnamed)")
ctf_integer(unsigned int, key, hash->size)
ctf_integer(unsigned int, index_size, hash->size)
ctf_integer(unsigned long, item_count, hash->count)
ctf_integer_hex(intptr_t, data_ptr, data)
)
)
TRACEPOINT_LOGLEVEL(frr_libfrr, hash_insert, TRACE_INFO)
TRACEPOINT_EVENT(
frr_libfrr,
hash_release,
TP_ARGS(struct hash *, hash, void *, data, void *, released_item),
TP_FIELDS(
ctf_string(name, hash->name ? hash->name : "(unnamed)")
ctf_integer(unsigned int, index_size, hash->size)
ctf_integer(unsigned long, item_count, hash->count)
ctf_integer_hex(intptr_t, data_ptr, data)
ctf_integer_hex(intptr_t, released_item, data)
)
)
TRACEPOINT_LOGLEVEL(frr_libfrr, hash_release, TRACE_INFO)
#define THREAD_SCHEDULE_ARGS \
TP_ARGS(struct thread_master *, master, const char *, funcname, \
const char *, schedfrom, int, fromln, struct thread **, \
thread_ptr, int, fd, int, val, void *, arg, long, time)
TRACEPOINT_EVENT_CLASS(
frr_libfrr,
thread_operation,
THREAD_SCHEDULE_ARGS,
TP_FIELDS(
ctf_string(threadmaster_name, master->name)
ctf_string(function_name, funcname ? funcname : "(unknown function)")
ctf_string(scheduled_from, schedfrom ? schedfrom : "(unknown file)")
ctf_integer(int, scheduled_on_line, fromln)
ctf_integer_hex(intptr_t, thread_addr, thread_ptr ? *thread_ptr : NULL)
ctf_integer(int, file_descriptor, fd)
ctf_integer(int, event_value, val)
ctf_integer_hex(intptr_t, argument_ptr, arg)
ctf_integer(long, timer, time)
)
)
#define THREAD_OPERATION_TRACEPOINT_INSTANCE(name) \
TRACEPOINT_EVENT_INSTANCE(frr_libfrr, thread_operation, name, \
THREAD_SCHEDULE_ARGS) \
TRACEPOINT_LOGLEVEL(frr_libfrr, name, TRACE_INFO)
THREAD_OPERATION_TRACEPOINT_INSTANCE(schedule_timer)
THREAD_OPERATION_TRACEPOINT_INSTANCE(schedule_event)
THREAD_OPERATION_TRACEPOINT_INSTANCE(schedule_read)
THREAD_OPERATION_TRACEPOINT_INSTANCE(schedule_write)
THREAD_OPERATION_TRACEPOINT_INSTANCE(thread_cancel)
THREAD_OPERATION_TRACEPOINT_INSTANCE(thread_cancel_async)
THREAD_OPERATION_TRACEPOINT_INSTANCE(thread_call)
TRACEPOINT_EVENT(
frr_libfrr,
frr_pthread_run,
TP_ARGS(
char *, name
),
TP_FIELDS(
ctf_string(frr_pthread_name, name)
)
)
TRACEPOINT_EVENT(
frr_libfrr,
frr_pthread_stop,
TP_ARGS(
char *, name
),
TP_FIELDS(
ctf_string(frr_pthread_name, name)
)
)
TRACEPOINT_EVENT(
frr_libfrr,
memalloc,
TP_ARGS(
struct memtype *, mt, void *, ptr, size_t, size
),
TP_FIELDS(
ctf_string(memtype, mt->name)
ctf_integer(size_t, size, size)
ctf_integer_hex(intptr_t, ptr, ptr)
)
)
TRACEPOINT_EVENT(
frr_libfrr,
memfree,
TP_ARGS(
struct memtype *, mt, void *, ptr
),
TP_FIELDS(
ctf_string(memtype, mt->name)
ctf_integer_hex(intptr_t, ptr, ptr)
)
)
TRACEPOINT_EVENT(
frr_libfrr,
list_add,
TP_ARGS(
struct list *, list, const void *, ptr
),
TP_FIELDS(
ctf_integer_hex(intptr_t, list, list)
ctf_integer(unsigned int, count, list->count)
ctf_integer_hex(intptr_t, ptr, ptr)
)
)
TRACEPOINT_EVENT(
frr_libfrr,
list_remove,
TP_ARGS(
struct list *, list, const void *, ptr
),
TP_FIELDS(
ctf_integer_hex(intptr_t, list, list)
ctf_integer(unsigned int, count, list->count)
ctf_integer_hex(intptr_t, ptr, ptr)
)
)
TRACEPOINT_EVENT(
frr_libfrr,
list_delete_node,
TP_ARGS(
struct list *, list, const void *, node
),
TP_FIELDS(
ctf_integer_hex(intptr_t, list, list)
ctf_integer(unsigned int, count, list->count)
ctf_integer_hex(intptr_t, node, node)
)
)
TRACEPOINT_EVENT(
frr_libfrr,
list_sort,
TP_ARGS(
struct list *, list
),
TP_FIELDS(
ctf_integer_hex(intptr_t, list, list)
ctf_integer(unsigned int, count, list->count)
)
)
TRACEPOINT_EVENT(
frr_libfrr,
route_node_get,
TP_ARGS(
struct route_table *, table, char *, prefix
),
TP_FIELDS(
ctf_integer_hex(intptr_t, table, table)
ctf_string(prefix, prefix)
)
)
/* clang-format on */
#include <lttng/tracepoint-event.h>
#include <lttng/tracelog.h>
#endif /* HAVE_LTTNG */
#endif /* _LIBFRR_TRACE_H_ */

View file

@ -23,6 +23,7 @@
#include "linklist.h"
#include "memory.h"
#include "libfrr_trace.h"
DEFINE_MTYPE_STATIC(LIB, LINK_LIST, "Link List")
DEFINE_MTYPE_STATIC(LIB, LINK_NODE, "Link Node")
@ -66,6 +67,8 @@ static void listnode_free(struct list *list, struct listnode *node)
struct listnode *listnode_add(struct list *list, void *val)
{
frrtrace(2, frr_libfrr, list_add, list, val);
struct listnode *node;
assert(val != NULL);
@ -281,6 +284,8 @@ void listnode_move_to_tail(struct list *l, struct listnode *n)
void listnode_delete(struct list *list, const void *val)
{
frrtrace(2, frr_libfrr, list_remove, list, val);
struct listnode *node = listnode_lookup(list, val);
if (node)
@ -360,6 +365,8 @@ struct listnode *listnode_lookup_nocheck(struct list *list, void *data)
void list_delete_node(struct list *list, struct listnode *node)
{
frrtrace(2, frr_libfrr, list_delete_node, list, node);
if (node->prev)
node->prev->next = node->next;
else
@ -374,6 +381,8 @@ void list_delete_node(struct list *list, struct listnode *node)
void list_sort(struct list *list, int (*cmp)(const void **, const void **))
{
frrtrace(1, frr_libfrr, list_sort, list);
struct listnode *ln, *nn;
int i = -1;
void *data;

View file

@ -29,6 +29,7 @@
#include "memory.h"
#include "log.h"
#include "libfrr_trace.h"
static struct memgroup *mg_first = NULL;
struct memgroup **mg_insert = &mg_first;
@ -77,6 +78,8 @@ static inline void mt_count_alloc(struct memtype *mt, size_t size, void *ptr)
static inline void mt_count_free(struct memtype *mt, void *ptr)
{
frrtrace(2, frr_libfrr, memfree, mt, ptr);
assert(mt->n_alloc);
atomic_fetch_sub_explicit(&mt->n_alloc, 1, memory_order_relaxed);
@ -89,6 +92,8 @@ static inline void mt_count_free(struct memtype *mt, void *ptr)
static inline void *mt_checkalloc(struct memtype *mt, void *ptr, size_t size)
{
frrtrace(3, frr_libfrr, memalloc, mt, ptr, size);
if (__builtin_expect(ptr == NULL, 0)) {
if (size) {
/* malloc(0) is allowed to return NULL */

View file

@ -3,7 +3,7 @@
#
lib_LTLIBRARIES += lib/libfrr.la
lib_libfrr_la_LDFLAGS = -version-info 0:0:0 -Xlinker -e_libfrr_version
lib_libfrr_la_LIBADD = $(LIBCAP) $(UNWIND_LIBS) $(LIBYANG_LIBS) $(LUA_LIB) $(LIBM)
lib_libfrr_la_LIBADD = $(LIBCAP) $(UNWIND_LIBS) $(LIBYANG_LIBS) $(LUA_LIB) $(UST_LIBS) $(LIBM)
lib_libfrr_la_SOURCES = \
lib/agg_table.c \
@ -46,6 +46,7 @@ lib_libfrr_la_SOURCES = \
lib/lib_errors.c \
lib/lib_vty.c \
lib/libfrr.c \
lib/libfrr_trace.c \
lib/linklist.c \
lib/log.c \
lib/log_filter.c \
@ -204,6 +205,7 @@ pkginclude_HEADERS += \
lib/lib_errors.h \
lib/lib_vty.h \
lib/libfrr.h \
lib/libfrr_trace.h \
lib/libospf.h \
lib/linklist.h \
lib/log.h \
@ -251,6 +253,7 @@ pkginclude_HEADERS += \
lib/table.h \
lib/termtable.h \
lib/thread.h \
lib/trace.h \
lib/typerb.h \
lib/typesafe.h \
lib/vector.h \
@ -401,7 +404,7 @@ lib_grammar_sandbox_LDADD = \
lib_clippy_CPPFLAGS = $(AM_CPPFLAGS) -D_GNU_SOURCE -DBUILDING_CLIPPY
lib_clippy_CFLAGS = $(PYTHON_CFLAGS)
lib_clippy_LDADD = $(PYTHON_LIBS)
lib_clippy_LDADD = $(PYTHON_LIBS) $(UST_LIBS)
lib_clippy_LDFLAGS = -export-dynamic
lib_clippy_SOURCES = \
lib/clippy.c \
@ -411,6 +414,7 @@ lib_clippy_SOURCES = \
lib/command_py.c \
lib/defun_lex.l \
lib/graph.c \
lib/libfrr_trace.c \
lib/memory.c \
lib/vector.c \
# end

View file

@ -27,6 +27,7 @@
#include "table.h"
#include "memory.h"
#include "sockunion.h"
#include "libfrr_trace.h"
DEFINE_MTYPE_STATIC(LIB, ROUTE_TABLE, "Route table")
DEFINE_MTYPE(LIB, ROUTE_NODE, "Route node")
@ -276,6 +277,12 @@ struct route_node *route_node_lookup_maynull(struct route_table *table,
struct route_node *route_node_get(struct route_table *table,
union prefixconstptr pu)
{
if (frrtrace_enabled(frr_libfrr, route_node_get)) {
char buf[PREFIX2STR_BUFFER];
prefix2str(pu, buf, sizeof(buf));
frrtrace(2, frr_libfrr, route_node_get, table, buf);
}
struct route_node search;
struct prefix *p = &search.p;

View file

@ -35,6 +35,7 @@
#include "frratomic.h"
#include "frr_pthread.h"
#include "lib_errors.h"
#include "libfrr_trace.h"
DEFINE_MTYPE_STATIC(LIB, THREAD, "Thread")
DEFINE_MTYPE_STATIC(LIB, THREAD_MASTER, "Thread master")
@ -787,6 +788,13 @@ struct thread *funcname_thread_add_read_write(int dir, struct thread_master *m,
struct thread *thread = NULL;
struct thread **thread_array;
if (dir == THREAD_READ)
frrtrace(9, frr_libfrr, schedule_read, m, funcname, schedfrom,
fromln, t_ptr, fd, 0, arg, 0);
else
frrtrace(9, frr_libfrr, schedule_write, m, funcname, schedfrom,
fromln, t_ptr, fd, 0, arg, 0);
assert(fd >= 0 && fd < m->fd_limit);
frr_with_mutex(&m->mtx) {
if (t_ptr && *t_ptr)
@ -861,6 +869,9 @@ funcname_thread_add_timer_timeval(struct thread_master *m,
assert(type == THREAD_TIMER);
assert(time_relative);
frrtrace(9, frr_libfrr, schedule_timer, m, funcname, schedfrom, fromln,
t_ptr, 0, 0, arg, (long)time_relative->tv_sec);
frr_with_mutex(&m->mtx) {
if (t_ptr && *t_ptr)
/* thread is already scheduled; don't reschedule */
@ -939,6 +950,9 @@ struct thread *funcname_thread_add_event(struct thread_master *m,
{
struct thread *thread = NULL;
frrtrace(9, frr_libfrr, schedule_event, m, funcname, schedfrom, fromln,
t_ptr, 0, val, arg, 0);
assert(m != NULL);
frr_with_mutex(&m->mtx) {
@ -1172,6 +1186,10 @@ void thread_cancel(struct thread **thread)
master = (*thread)->master;
frrtrace(9, frr_libfrr, thread_cancel, master, thread->funcname,
thread->schedfrom, thread->schedfrom_line, NULL, thread->u.fd,
thread->u.val, thread->arg, thread->u.sands.tv_sec);
assert(master->owner == pthread_self());
frr_with_mutex(&master->mtx) {
@ -1213,6 +1231,17 @@ void thread_cancel_async(struct thread_master *master, struct thread **thread,
void *eventobj)
{
assert(!(thread && eventobj) && (thread || eventobj));
if (thread && *thread)
frrtrace(9, frr_libfrr, thread_cancel_async, master,
(*thread)->funcname, (*thread)->schedfrom,
(*thread)->schedfrom_line, NULL, (*thread)->u.fd,
(*thread)->u.val, (*thread)->arg,
(*thread)->u.sands.tv_sec);
else
frrtrace(9, frr_libfrr, thread_cancel_async, master, NULL, NULL,
0, NULL, 0, 0, eventobj, 0);
assert(master->owner != pthread_self());
frr_with_mutex(&master->mtx) {
@ -1591,6 +1620,10 @@ void thread_call(struct thread *thread)
GETRUSAGE(&before);
thread->real = before.real;
frrtrace(9, frr_libfrr, thread_call, thread->master, thread->funcname,
thread->schedfrom, thread->schedfrom_line, NULL, thread->u.fd,
thread->u.val, thread->arg, thread->u.sands.tv_sec);
pthread_setspecific(thread_current, thread);
(*thread->func)(thread);
pthread_setspecific(thread_current, NULL);

80
lib/trace.h Normal file
View file

@ -0,0 +1,80 @@
/* Tracing macros
*
* Wraps tracepoint macros for different tracing systems to allow switching
* between them at compile time.
*
* This should not be included directly by source files wishing to provide
* tracepoints. Instead, write a header that defines LTTng tracepoints and
* which includes this header, and include your new header in your source. USDT
* probes do not need tracepoint definitions, but are less capable than LTTng
* tracepoints.
*
* Copyright (C) 2020 NVIDIA Corporation
* Quentin Young
*
* This program is free software; you can redistribute it and/or modify it
* under the terms of the GNU General Public License as published by the Free
* Software Foundation; either version 2 of the License, or (at your option)
* any later version.
*
* This program 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 General Public License for
* more details.
*
* You should have received a copy of the GNU General Public License along
* with this program; see the file COPYING; if not, write to the Free Software
* Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA
*/
#ifndef _TRACE_H_
#define _TRACE_H_
#ifdef HAVE_CONFIG_H
#include "config.h"
#endif /* HAVE_CONFIG_H */
/*
* Provided here:
* - frrtrace(n, provider, name, ...args...)
* - frrtrace_enabled(provider, name)
* - frrtracelog(level, msg, ...)
*
* Use frrtrace() to define tracepoints. n is the number of arguments; this is
* needed because USDT probe definitions use DTRACE_PROBEn macros, so the
* number of args must be passed in order to expand the correct macro.
*
* frrtrace_enabled() maps to tracepoint_enabled() under LTTng and is always
* true when using USDT. In the future it could be mapped to USDT semaphores
* but this is not implemented at present.
*
* frrtracelog() maps to tracelog() under LTTng and should only be used in zlog
* core code, to propagate zlog messages to LTTng. It expands to nothing
* otherwise.
*/
#if defined(HAVE_LTTNG)
#define frrtrace(nargs, provider, name, ...) \
tracepoint(provider, name, ## __VA_ARGS__)
#define frrtrace_enabled(...) tracepoint_enabled(__VA_ARGS__)
#define frrtracelog(...) tracelog(__VA_ARGS__)
#elif defined(HAVE_USDT)
#include "sys/sdt.h"
#define frrtrace(nargs, provider, name, ...) \
DTRACE_PROBE##nargs(provider, name, ## __VA_ARGS__)
#define frrtrace_enabled(...) true
#define frrtracelog(...)
#else
#define frrtrace(nargs, provider, name, ...) (void)0
#define frrtrace_enabled(...) false
#define frrtracelog(...) (void)0
#endif
#endif /* _TRACE_H_ */

View file

@ -27,6 +27,8 @@ extern void _zlog_assert_failed(const char *assertion, const char *file,
unsigned int line, const char *function)
__attribute__((noreturn));
#undef __ASSERT_FUNCTION
#if defined(__STDC_VERSION__) && __STDC_VERSION__ >= 199901L
#define __ASSERT_FUNCTION __func__
#elif defined(__GNUC__)

View file

@ -52,6 +52,7 @@
#include "printfrr.h"
#include "frrcu.h"
#include "zlog.h"
#include "libfrr_trace.h"
DEFINE_MTYPE_STATIC(LIB, LOG_MESSAGE, "log message")
DEFINE_MTYPE_STATIC(LIB, LOG_TLSBUF, "log thread-local buffer")
@ -450,6 +451,34 @@ void vzlog(int prio, const char *fmt, va_list ap)
{
struct zlog_tls *zlog_tls = zlog_tls_get();
#ifdef HAVE_LTTNG
va_list copy;
va_copy(copy, ap);
char *msg = vasprintfrr(MTYPE_LOG_MESSAGE, fmt, copy);
switch (prio) {
case LOG_ERR:
frrtracelog(TRACE_ERR, msg);
break;
case LOG_WARNING:
frrtracelog(TRACE_WARNING, msg);
break;
case LOG_DEBUG:
frrtracelog(TRACE_DEBUG, msg);
break;
case LOG_NOTICE:
frrtracelog(TRACE_DEBUG, msg);
break;
case LOG_INFO:
default:
frrtracelog(TRACE_INFO, msg);
break;
}
va_end(copy);
XFREE(MTYPE_LOG_MESSAGE, msg);
#endif
if (zlog_tls)
vzlog_tls(zlog_tls, prio, fmt, ap);
else