diff options
| author | Mark Stapp <mjs@voltanet.io> | 2020-10-24 16:50:35 -0400 |
|---|---|---|
| committer | GitHub <noreply@github.com> | 2020-10-24 16:50:35 -0400 |
| commit | cbd492990db19b51a24bdd6e8bfec4f79c0f11d5 (patch) | |
| tree | 660d4e662cd49d32b968e2b00cb18e1928c49f90 | |
| parent | 874e77acceba36bdd1d15d5b368ce9e367e3628a (diff) | |
| parent | fc3ee1e04105c87e5d46ca99d1ac442bcc02d121 (diff) | |
Merge pull request #7194 from qlyoung/tracing
Tracing
| -rw-r--r-- | bgpd/bgp_io.c | 2 | ||||
| -rw-r--r-- | bgpd/bgp_packet.c | 7 | ||||
| -rw-r--r-- | bgpd/bgp_route.c | 72 | ||||
| -rw-r--r-- | bgpd/bgp_trace.c | 4 | ||||
| -rw-r--r-- | bgpd/bgp_trace.h | 131 | ||||
| -rw-r--r-- | bgpd/subdir.am | 6 | ||||
| -rwxr-xr-x | configure.ac | 28 | ||||
| -rw-r--r-- | doc/developer/index.rst | 1 | ||||
| -rw-r--r-- | doc/developer/tracing.rst | 314 | ||||
| -rw-r--r-- | lib/frr_pthread.c | 5 | ||||
| -rw-r--r-- | lib/hash.c | 14 | ||||
| -rw-r--r-- | lib/libfrr_trace.c | 4 | ||||
| -rw-r--r-- | lib/libfrr_trace.h | 240 | ||||
| -rw-r--r-- | lib/linklist.c | 9 | ||||
| -rw-r--r-- | lib/memory.c | 5 | ||||
| -rw-r--r-- | lib/subdir.am | 8 | ||||
| -rw-r--r-- | lib/table.c | 7 | ||||
| -rw-r--r-- | lib/thread.c | 33 | ||||
| -rw-r--r-- | lib/trace.h | 80 | ||||
| -rw-r--r-- | lib/zassert.h | 2 | ||||
| -rw-r--r-- | lib/zlog.c | 29 |
21 files changed, 980 insertions, 21 deletions
diff --git a/bgpd/bgp_io.c b/bgpd/bgp_io.c index b14ac8b782..38455b5e02 100644 --- a/bgpd/bgp_io.c +++ b/bgpd/bgp_io.c @@ -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); } diff --git a/bgpd/bgp_packet.c b/bgpd/bgp_packet.c index ed22f6711c..2ebac56670 100644 --- a/bgpd/bgp_packet.c +++ b/bgpd/bgp_packet.c @@ -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); diff --git a/bgpd/bgp_route.c b/bgpd/bgp_route.c index f4c1dd1d2b..b637191d10 100644 --- a/bgpd/bgp_route.c +++ b/bgpd/bgp_route.c @@ -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; + } + } + + 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"); } - return FILTER_PERMIT; +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 diff --git a/bgpd/bgp_trace.c b/bgpd/bgp_trace.c new file mode 100644 index 0000000000..2ebc63b6b5 --- /dev/null +++ b/bgpd/bgp_trace.c @@ -0,0 +1,4 @@ +#define TRACEPOINT_CREATE_PROBES +#define TRACEPOINT_DEFINE + +#include "bgp_trace.h" diff --git a/bgpd/bgp_trace.h b/bgpd/bgp_trace.h new file mode 100644 index 0000000000..2566ffb928 --- /dev/null +++ b/bgpd/bgp_trace.h @@ -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 */ diff --git a/bgpd/subdir.am b/bgpd/subdir.am index 717e157078..3cb32b1f08 100644 --- a/bgpd/subdir.am +++ b/bgpd/subdir.am @@ -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 diff --git a/configure.ac b/configure.ac index 8e86ba87ff..bda9a34504 100755 --- a/configure.ac +++ b/configure.ac @@ -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 ------ diff --git a/doc/developer/index.rst b/doc/developer/index.rst index 1f803b3772..1ba0f31c8a 100644 --- a/doc/developer/index.rst +++ b/doc/developer/index.rst @@ -9,6 +9,7 @@ FRRouting Developer's Guide packaging process-architecture library + tracing testing bgpd fpm diff --git a/doc/developer/tracing.rst b/doc/developer/tracing.rst new file mode 100644 index 0000000000..ee0a6be008 --- /dev/null +++ b/doc/developer/tracing.rst @@ -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. diff --git a/lib/frr_pthread.c b/lib/frr_pthread.c index da9594ed80..3f0179fbc1 100644 --- a/lib/frr_pthread.c +++ b/lib/frr_pthread.c @@ -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; diff --git a/lib/hash.c b/lib/hash.c index 85982774ac..ed429b77d0 100644 --- a/lib/hash.c +++ b/lib/hash.c @@ -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 *), diff --git a/lib/libfrr_trace.c b/lib/libfrr_trace.c new file mode 100644 index 0000000000..2f300e6ee1 --- /dev/null +++ b/lib/libfrr_trace.c @@ -0,0 +1,4 @@ +#define TRACEPOINT_CREATE_PROBES +#define TRACEPOINT_DEFINE + +#include "libfrr_trace.h" diff --git a/lib/libfrr_trace.h b/lib/libfrr_trace.h new file mode 100644 index 0000000000..7215007ffb --- /dev/null +++ b/lib/libfrr_trace.h @@ -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_ */ diff --git a/lib/linklist.c b/lib/linklist.c index 84dc6e1419..43c2002231 100644 --- a/lib/linklist.c +++ b/lib/linklist.c @@ -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; diff --git a/lib/memory.c b/lib/memory.c index 2c902d123b..f715044ea3 100644 --- a/lib/memory.c +++ b/lib/memory.c @@ -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 */ diff --git a/lib/subdir.am b/lib/subdir.am index 55f127b019..ed3c30799d 100644 --- a/lib/subdir.am +++ b/lib/subdir.am @@ -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 diff --git a/lib/table.c b/lib/table.c index b315637f19..89e32182b5 100644 --- a/lib/table.c +++ b/lib/table.c @@ -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; diff --git a/lib/thread.c b/lib/thread.c index 012194a47b..1765de9573 100644 --- a/lib/thread.c +++ b/lib/thread.c @@ -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); diff --git a/lib/trace.h b/lib/trace.h new file mode 100644 index 0000000000..73fc10a556 --- /dev/null +++ b/lib/trace.h @@ -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_ */ diff --git a/lib/zassert.h b/lib/zassert.h index e50a88f407..e6b254ee8d 100644 --- a/lib/zassert.h +++ b/lib/zassert.h @@ -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__) diff --git a/lib/zlog.c b/lib/zlog.c index 8dfd20371b..e77feec5f2 100644 --- a/lib/zlog.c +++ b/lib/zlog.c @@ -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 |
