diff options
author | David S. Miller <davem@davemloft.net> | 2020-08-22 21:44:37 +0200 |
---|---|---|
committer | David S. Miller <davem@davemloft.net> | 2020-08-22 21:44:37 +0200 |
commit | d7223aa5867134b9923b42e1245801bd790a1d8c (patch) | |
tree | 86ffc9f5b39c34d10bad377c1d7c2ac223836345 /net | |
parent | net: dccp: Convert to use the preferred fallthrough macro (diff) | |
parent | docs: networking: add tracepoint info to l2tp.rst (diff) | |
download | linux-d7223aa5867134b9923b42e1245801bd790a1d8c.tar.xz linux-d7223aa5867134b9923b42e1245801bd790a1d8c.zip |
Merge branch 'l2tp-replace-custom-logging-code-with-tracepoints'
Tom Parkin says:
====================
l2tp: replace custom logging code with tracepoints
The l2tp subsystem implemented custom logging macros for debugging
purposes which were controlled using a set of debugging flags in each
tunnel and session structure.
A more standard and easier-to-use approach is to use tracepoints.
This patchset refactors l2tp to:
* remove excessive logging
* tweak useful log messages to use the standard pr_* calls for logging
rather than the l2tp wrappers
* replace debug-level logging with tracepoints
* add tracepoints for capturing tunnel and session lifetime events
I note that checkpatch.pl warns about the layout of code in the
newly-added file net/l2tp/trace.h. When adding this file I followed the
example(s) of other tracepoint files in the net/ subtree since it seemed
preferable to adhere to the prevailing style rather than follow
checkpatch.pl's advice in this instance. If that's the wrong
approach please let me know.
v1 -> v2
* Fix up a build warning found by the kernel test robot
====================
Signed-off-by: David S. Miller <davem@davemloft.net>
Diffstat (limited to 'net')
-rw-r--r-- | net/l2tp/Makefile | 2 | ||||
-rw-r--r-- | net/l2tp/l2tp_core.c | 192 | ||||
-rw-r--r-- | net/l2tp/l2tp_core.h | 23 | ||||
-rw-r--r-- | net/l2tp/l2tp_debugfs.c | 4 | ||||
-rw-r--r-- | net/l2tp/l2tp_eth.c | 11 | ||||
-rw-r--r-- | net/l2tp/l2tp_ip.c | 15 | ||||
-rw-r--r-- | net/l2tp/l2tp_ip6.c | 15 | ||||
-rw-r--r-- | net/l2tp/l2tp_netlink.c | 16 | ||||
-rw-r--r-- | net/l2tp/l2tp_ppp.c | 55 | ||||
-rw-r--r-- | net/l2tp/trace.h | 211 |
10 files changed, 283 insertions, 261 deletions
diff --git a/net/l2tp/Makefile b/net/l2tp/Makefile index 399a7e5db2f4..cf8f27071d3f 100644 --- a/net/l2tp/Makefile +++ b/net/l2tp/Makefile @@ -5,6 +5,8 @@ obj-$(CONFIG_L2TP) += l2tp_core.o +CFLAGS_l2tp_core.o += -I$(src) + # Build l2tp as modules if L2TP is M obj-$(subst y,$(CONFIG_L2TP),$(CONFIG_PPPOL2TP)) += l2tp_ppp.o obj-$(subst y,$(CONFIG_L2TP),$(CONFIG_L2TP_IP)) += l2tp_ip.o diff --git a/net/l2tp/l2tp_core.c b/net/l2tp/l2tp_core.c index 701fc72ad9f4..560c687f5457 100644 --- a/net/l2tp/l2tp_core.c +++ b/net/l2tp/l2tp_core.c @@ -61,6 +61,10 @@ #include <linux/atomic.h> #include "l2tp_core.h" +#include "trace.h" + +#define CREATE_TRACE_POINTS +#include "trace.h" #define L2TP_DRV_VERSION "V2.0" @@ -151,6 +155,7 @@ l2tp_session_id_hash(struct l2tp_tunnel *tunnel, u32 session_id) static void l2tp_tunnel_free(struct l2tp_tunnel *tunnel) { + trace_free_tunnel(tunnel); sock_put(tunnel->sock); /* the tunnel is freed in the socket destructor */ } @@ -159,6 +164,8 @@ static void l2tp_session_free(struct l2tp_session *session) { struct l2tp_tunnel *tunnel = session->tunnel; + trace_free_session(session); + if (tunnel) { if (WARN_ON(tunnel->magic != L2TP_TUNNEL_MAGIC)) goto out; @@ -381,6 +388,8 @@ int l2tp_session_register(struct l2tp_session *session, hlist_add_head(&session->hlist, head); write_unlock_bh(&tunnel->hlist_lock); + trace_register_session(session); + return 0; err_tlock_pnlock: @@ -409,10 +418,6 @@ static void l2tp_recv_queue_skb(struct l2tp_session *session, struct sk_buff *sk skb_queue_walk_safe(&session->reorder_q, skbp, tmp) { if (L2TP_SKB_CB(skbp)->ns > ns) { __skb_queue_before(&session->reorder_q, skbp, skb); - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: pkt %hu, inserted before %hu, reorder_q len=%d\n", - session->name, ns, L2TP_SKB_CB(skbp)->ns, - skb_queue_len(&session->reorder_q)); atomic_long_inc(&session->stats.rx_oos_packets); goto out; } @@ -445,9 +450,7 @@ static void l2tp_recv_dequeue_skb(struct l2tp_session *session, struct sk_buff * /* Bump our Nr */ session->nr++; session->nr &= session->nr_max; - - l2tp_dbg(session, L2TP_MSG_SEQ, "%s: updated nr to %hu\n", - session->name, session->nr); + trace_session_seqnum_update(session); } /* call private receive handler */ @@ -472,37 +475,27 @@ static void l2tp_recv_dequeue(struct l2tp_session *session) start: spin_lock_bh(&session->reorder_q.lock); skb_queue_walk_safe(&session->reorder_q, skb, tmp) { - if (time_after(jiffies, L2TP_SKB_CB(skb)->expires)) { + struct l2tp_skb_cb *cb = L2TP_SKB_CB(skb); + + /* If the packet has been pending on the queue for too long, discard it */ + if (time_after(jiffies, cb->expires)) { atomic_long_inc(&session->stats.rx_seq_discards); atomic_long_inc(&session->stats.rx_errors); - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: oos pkt %u len %d discarded (too old), waiting for %u, reorder_q_len=%d\n", - session->name, L2TP_SKB_CB(skb)->ns, - L2TP_SKB_CB(skb)->length, session->nr, - skb_queue_len(&session->reorder_q)); + trace_session_pkt_expired(session, cb->ns); session->reorder_skip = 1; __skb_unlink(skb, &session->reorder_q); kfree_skb(skb); continue; } - if (L2TP_SKB_CB(skb)->has_seq) { + if (cb->has_seq) { if (session->reorder_skip) { - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: advancing nr to next pkt: %u -> %u", - session->name, session->nr, - L2TP_SKB_CB(skb)->ns); session->reorder_skip = 0; - session->nr = L2TP_SKB_CB(skb)->ns; + session->nr = cb->ns; + trace_session_seqnum_reset(session); } - if (L2TP_SKB_CB(skb)->ns != session->nr) { - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: holding oos pkt %u len %d, waiting for %u, reorder_q_len=%d\n", - session->name, L2TP_SKB_CB(skb)->ns, - L2TP_SKB_CB(skb)->length, session->nr, - skb_queue_len(&session->reorder_q)); + if (cb->ns != session->nr) goto out; - } } __skb_unlink(skb, &session->reorder_q); @@ -535,14 +528,13 @@ static int l2tp_seq_check_rx_window(struct l2tp_session *session, u32 nr) */ static int l2tp_recv_data_seq(struct l2tp_session *session, struct sk_buff *skb) { - if (!l2tp_seq_check_rx_window(session, L2TP_SKB_CB(skb)->ns)) { + struct l2tp_skb_cb *cb = L2TP_SKB_CB(skb); + + if (!l2tp_seq_check_rx_window(session, cb->ns)) { /* Packet sequence number is outside allowed window. * Discard it. */ - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: pkt %u len %d discarded, outside window, nr=%u\n", - session->name, L2TP_SKB_CB(skb)->ns, - L2TP_SKB_CB(skb)->length, session->nr); + trace_session_pkt_outside_rx_window(session, cb->ns); goto discard; } @@ -559,10 +551,10 @@ static int l2tp_recv_data_seq(struct l2tp_session *session, struct sk_buff *skb) * is seen. After nr_oos_count_max in-sequence packets, reset the * sequence number to re-enable packet reception. */ - if (L2TP_SKB_CB(skb)->ns == session->nr) { + if (cb->ns == session->nr) { skb_queue_tail(&session->reorder_q, skb); } else { - u32 nr_oos = L2TP_SKB_CB(skb)->ns; + u32 nr_oos = cb->ns; u32 nr_next = (session->nr_oos + 1) & session->nr_max; if (nr_oos == nr_next) @@ -573,17 +565,10 @@ static int l2tp_recv_data_seq(struct l2tp_session *session, struct sk_buff *skb) session->nr_oos = nr_oos; if (session->nr_oos_count > session->nr_oos_count_max) { session->reorder_skip = 1; - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: %d oos packets received. Resetting sequence numbers\n", - session->name, session->nr_oos_count); } if (!session->reorder_skip) { atomic_long_inc(&session->stats.rx_seq_discards); - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: oos pkt %u len %d discarded, waiting for %u, reorder_q_len=%d\n", - session->name, L2TP_SKB_CB(skb)->ns, - L2TP_SKB_CB(skb)->length, session->nr, - skb_queue_len(&session->reorder_q)); + trace_session_pkt_oos(session, cb->ns); goto discard; } skb_queue_tail(&session->reorder_q, skb); @@ -660,16 +645,14 @@ void l2tp_recv_common(struct l2tp_session *session, struct sk_buff *skb, int length) { struct l2tp_tunnel *tunnel = session->tunnel; - u32 ns = 0, nr = 0; int offset; /* Parse and check optional cookie */ if (session->peer_cookie_len > 0) { if (memcmp(ptr, &session->peer_cookie[0], session->peer_cookie_len)) { - l2tp_info(tunnel, L2TP_MSG_DATA, - "%s: cookie mismatch (%u/%u). Discarding.\n", - tunnel->name, tunnel->tunnel_id, - session->session_id); + pr_warn_ratelimited("%s: cookie mismatch (%u/%u). Discarding.\n", + tunnel->name, tunnel->tunnel_id, + session->session_id); atomic_long_inc(&session->stats.rx_cookie_discards); goto discard; } @@ -686,32 +669,21 @@ void l2tp_recv_common(struct l2tp_session *session, struct sk_buff *skb, L2TP_SKB_CB(skb)->has_seq = 0; if (tunnel->version == L2TP_HDR_VER_2) { if (hdrflags & L2TP_HDRFLAG_S) { - ns = ntohs(*(__be16 *)ptr); - ptr += 2; - nr = ntohs(*(__be16 *)ptr); - ptr += 2; - /* Store L2TP info in the skb */ - L2TP_SKB_CB(skb)->ns = ns; + L2TP_SKB_CB(skb)->ns = ntohs(*(__be16 *)ptr); L2TP_SKB_CB(skb)->has_seq = 1; + ptr += 2; + /* Skip past nr in the header */ + ptr += 2; - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: recv data ns=%u, nr=%u, session nr=%u\n", - session->name, ns, nr, session->nr); } } else if (session->l2specific_type == L2TP_L2SPECTYPE_DEFAULT) { u32 l2h = ntohl(*(__be32 *)ptr); if (l2h & 0x40000000) { - ns = l2h & 0x00ffffff; - /* Store L2TP info in the skb */ - L2TP_SKB_CB(skb)->ns = ns; + L2TP_SKB_CB(skb)->ns = l2h & 0x00ffffff; L2TP_SKB_CB(skb)->has_seq = 1; - - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: recv data ns=%u, session nr=%u\n", - session->name, ns, session->nr); } ptr += 4; } @@ -722,9 +694,7 @@ void l2tp_recv_common(struct l2tp_session *session, struct sk_buff *skb, * configure it so. */ if (!session->lns_mode && !session->send_seq) { - l2tp_info(session, L2TP_MSG_SEQ, - "%s: requested to enable seq numbers by LNS\n", - session->name); + trace_session_seqnum_lns_enable(session); session->send_seq = 1; l2tp_session_set_header_len(session, tunnel->version); } @@ -733,9 +703,8 @@ void l2tp_recv_common(struct l2tp_session *session, struct sk_buff *skb, * If user has configured mandatory sequence numbers, discard. */ if (session->recv_seq) { - l2tp_warn(session, L2TP_MSG_SEQ, - "%s: recv data has no seq numbers when required. Discarding.\n", - session->name); + pr_warn_ratelimited("%s: recv data has no seq numbers when required. Discarding.\n", + session->name); atomic_long_inc(&session->stats.rx_seq_discards); goto discard; } @@ -746,15 +715,12 @@ void l2tp_recv_common(struct l2tp_session *session, struct sk_buff *skb, * LAC is broken. Discard the frame. */ if (!session->lns_mode && session->send_seq) { - l2tp_info(session, L2TP_MSG_SEQ, - "%s: requested to disable seq numbers by LNS\n", - session->name); + trace_session_seqnum_lns_disable(session); session->send_seq = 0; l2tp_session_set_header_len(session, tunnel->version); } else if (session->send_seq) { - l2tp_warn(session, L2TP_MSG_SEQ, - "%s: recv data has no seq numbers when required. Discarding.\n", - session->name); + pr_warn_ratelimited("%s: recv data has no seq numbers when required. Discarding.\n", + session->name); atomic_long_inc(&session->stats.rx_seq_discards); goto discard; } @@ -847,22 +813,11 @@ static int l2tp_udp_recv_core(struct l2tp_tunnel *tunnel, struct sk_buff *skb) /* Short packet? */ if (!pskb_may_pull(skb, L2TP_HDR_SIZE_MAX)) { - l2tp_info(tunnel, L2TP_MSG_DATA, - "%s: recv short packet (len=%d)\n", - tunnel->name, skb->len); + pr_warn_ratelimited("%s: recv short packet (len=%d)\n", + tunnel->name, skb->len); goto error; } - /* Trace packet contents, if enabled */ - if (tunnel->debug & L2TP_MSG_DATA) { - length = min(32u, skb->len); - if (!pskb_may_pull(skb, length)) - goto error; - - pr_debug("%s: recv\n", tunnel->name); - print_hex_dump_bytes("", DUMP_PREFIX_OFFSET, skb->data, length); - } - /* Point to L2TP header */ optr = skb->data; ptr = skb->data; @@ -873,9 +828,8 @@ static int l2tp_udp_recv_core(struct l2tp_tunnel *tunnel, struct sk_buff *skb) /* Check protocol version */ version = hdrflags & L2TP_HDR_VER_MASK; if (version != tunnel->version) { - l2tp_info(tunnel, L2TP_MSG_DATA, - "%s: recv protocol version mismatch: got %d expected %d\n", - tunnel->name, version, tunnel->version); + pr_warn_ratelimited("%s: recv protocol version mismatch: got %d expected %d\n", + tunnel->name, version, tunnel->version); goto error; } @@ -883,12 +837,8 @@ static int l2tp_udp_recv_core(struct l2tp_tunnel *tunnel, struct sk_buff *skb) length = skb->len; /* If type is control packet, it is handled by userspace. */ - if (hdrflags & L2TP_HDRFLAG_T) { - l2tp_dbg(tunnel, L2TP_MSG_DATA, - "%s: recv control packet, len=%d\n", - tunnel->name, length); + if (hdrflags & L2TP_HDRFLAG_T) goto error; - } /* Skip flags */ ptr += 2; @@ -917,9 +867,8 @@ static int l2tp_udp_recv_core(struct l2tp_tunnel *tunnel, struct sk_buff *skb) l2tp_session_dec_refcount(session); /* Not found? Pass to userspace to deal with */ - l2tp_info(tunnel, L2TP_MSG_DATA, - "%s: no session found (%u/%u). Passing up.\n", - tunnel->name, tunnel_id, session_id); + pr_warn_ratelimited("%s: no session found (%u/%u). Passing up.\n", + tunnel->name, tunnel_id, session_id); goto error; } @@ -953,9 +902,6 @@ int l2tp_udp_encap_recv(struct sock *sk, struct sk_buff *skb) if (!tunnel) goto pass_up; - l2tp_dbg(tunnel, L2TP_MSG_DATA, "%s: received %d bytes\n", - tunnel->name, skb->len); - if (l2tp_udp_recv_core(tunnel, skb)) goto pass_up; @@ -993,8 +939,7 @@ static int l2tp_build_l2tpv2_header(struct l2tp_session *session, void *buf) *bufp++ = 0; session->ns++; session->ns &= 0xffff; - l2tp_dbg(session, L2TP_MSG_SEQ, "%s: updated ns to %u\n", - session->name, session->ns); + trace_session_seqnum_update(session); } return bufp - optr; @@ -1030,9 +975,7 @@ static int l2tp_build_l2tpv3_header(struct l2tp_session *session, void *buf) l2h = 0x40000000 | session->ns; session->ns++; session->ns &= 0xffffff; - l2tp_dbg(session, L2TP_MSG_SEQ, - "%s: updated ns to %u\n", - session->name, session->ns); + trace_session_seqnum_update(session); } *((__be32 *)bufp) = htonl(l2h); @@ -1049,23 +992,6 @@ static void l2tp_xmit_core(struct l2tp_session *session, struct sk_buff *skb, unsigned int len = skb->len; int error; - /* Debug */ - if (session->send_seq) - l2tp_dbg(session, L2TP_MSG_DATA, "%s: send %zd bytes, ns=%u\n", - session->name, data_len, session->ns - 1); - else - l2tp_dbg(session, L2TP_MSG_DATA, "%s: send %zd bytes\n", - session->name, data_len); - - if (session->debug & L2TP_MSG_DATA) { - int uhlen = (tunnel->encap == L2TP_ENCAPTYPE_UDP) ? sizeof(struct udphdr) : 0; - unsigned char *datap = skb->data + uhlen; - - pr_debug("%s: xmit\n", session->name); - print_hex_dump_bytes("", DUMP_PREFIX_OFFSET, - datap, min_t(size_t, 32, len - uhlen)); - } - /* Queue the packet to IP for output */ skb->ignore_df = 1; skb_dst_drop(skb); @@ -1195,8 +1121,6 @@ static void l2tp_tunnel_destruct(struct sock *sk) if (!tunnel) goto end; - l2tp_info(tunnel, L2TP_MSG_CONTROL, "%s: closing...\n", tunnel->name); - /* Disable udp encapsulation */ switch (tunnel->encap) { case L2TP_ENCAPTYPE_UDP: @@ -1255,9 +1179,6 @@ static void l2tp_tunnel_closeall(struct l2tp_tunnel *tunnel) struct hlist_node *tmp; struct l2tp_session *session; - l2tp_info(tunnel, L2TP_MSG_CONTROL, "%s: closing all sessions...\n", - tunnel->name); - write_lock_bh(&tunnel->hlist_lock); tunnel->acpt_newsess = false; for (hash = 0; hash < L2TP_HASH_SIZE; hash++) { @@ -1265,9 +1186,6 @@ again: hlist_for_each_safe(walk, tmp, &tunnel->session_hlist[hash]) { session = hlist_entry(walk, struct l2tp_session, hlist); - l2tp_info(session, L2TP_MSG_CONTROL, - "%s: closing session\n", session->name); - hlist_del_init(&session->hlist); if (test_and_set_bit(0, &session->dead)) @@ -1483,16 +1401,12 @@ int l2tp_tunnel_create(struct net *net, int fd, int version, u32 tunnel_id, u32 tunnel->version = version; tunnel->tunnel_id = tunnel_id; tunnel->peer_tunnel_id = peer_tunnel_id; - tunnel->debug = L2TP_DEFAULT_DEBUG_FLAGS; tunnel->magic = L2TP_TUNNEL_MAGIC; sprintf(&tunnel->name[0], "tunl %u", tunnel_id); rwlock_init(&tunnel->hlist_lock); tunnel->acpt_newsess = true; - if (cfg) - tunnel->debug = cfg->debug; - tunnel->encap = encap; refcount_set(&tunnel->ref_count, 1); @@ -1597,6 +1511,8 @@ int l2tp_tunnel_register(struct l2tp_tunnel *tunnel, struct net *net, "l2tp_sock"); sk->sk_allocation = GFP_ATOMIC; + trace_register_tunnel(tunnel); + if (tunnel->fd >= 0) sockfd_put(sock); @@ -1617,6 +1533,7 @@ EXPORT_SYMBOL_GPL(l2tp_tunnel_register); void l2tp_tunnel_delete(struct l2tp_tunnel *tunnel) { if (!test_and_set_bit(0, &tunnel->dead)) { + trace_delete_tunnel(tunnel); l2tp_tunnel_inc_refcount(tunnel); queue_work(l2tp_wq, &tunnel->del_work); } @@ -1628,6 +1545,7 @@ void l2tp_session_delete(struct l2tp_session *session) if (test_and_set_bit(0, &session->dead)) return; + trace_delete_session(session); l2tp_session_unhash(session); l2tp_session_queue_purge(session); if (session->session_close) @@ -1686,12 +1604,8 @@ struct l2tp_session *l2tp_session_create(int priv_size, struct l2tp_tunnel *tunn INIT_HLIST_NODE(&session->hlist); INIT_HLIST_NODE(&session->global_hlist); - /* Inherit debug options from tunnel */ - session->debug = tunnel->debug; - if (cfg) { session->pwtype = cfg->pw_type; - session->debug = cfg->debug; session->send_seq = cfg->send_seq; session->recv_seq = cfg->recv_seq; session->lns_mode = cfg->lns_mode; diff --git a/net/l2tp/l2tp_core.h b/net/l2tp/l2tp_core.h index 3468d6b177a0..07249c5f22ef 100644 --- a/net/l2tp/l2tp_core.h +++ b/net/l2tp/l2tp_core.h @@ -51,7 +51,6 @@ struct l2tp_session_cfg { unsigned int lns_mode:1; /* behave as LNS? * LAC enables sequence numbers under LNS control. */ - int debug; /* bitmask of debug message categories */ u16 l2specific_type; /* Layer 2 specific type */ u8 cookie[8]; /* optional cookie */ int cookie_len; /* 0, 4 or 8 bytes */ @@ -66,6 +65,7 @@ struct l2tp_session_cfg { * Is linked into a per-tunnel session hashlist; and in the case of an L2TPv3 session into * an additional per-net ("global") hashlist. */ +#define L2TP_SESSION_NAME_MAX 32 struct l2tp_session { int magic; /* should be L2TP_SESSION_MAGIC */ long dead; @@ -90,14 +90,13 @@ struct l2tp_session { struct hlist_node hlist; /* hash list node */ refcount_t ref_count; - char name[32]; /* for logging */ + char name[L2TP_SESSION_NAME_MAX]; /* for logging */ char ifname[IFNAMSIZ]; unsigned int recv_seq:1; /* expect receive packets with sequence numbers? */ unsigned int send_seq:1; /* send packets with sequence numbers? */ unsigned int lns_mode:1; /* behave as LNS? * LAC enables sequence numbers under LNS control. */ - int debug; /* bitmask of debug message categories */ int reorder_timeout; /* configured reorder timeout (in jiffies) */ int reorder_skip; /* set if skip to next nr */ enum l2tp_pwtype pwtype; @@ -131,7 +130,6 @@ struct l2tp_session { /* L2TP tunnel configuration */ struct l2tp_tunnel_cfg { - int debug; /* bitmask of debug message categories */ enum l2tp_encap_type encap; /* Used only for kernel-created sockets */ @@ -154,6 +152,7 @@ struct l2tp_tunnel_cfg { * Maintains a hashlist of sessions belonging to the tunnel instance. * Is linked into a per-net list of tunnels. */ +#define L2TP_TUNNEL_NAME_MAX 20 struct l2tp_tunnel { int magic; /* Should be L2TP_TUNNEL_MAGIC */ @@ -170,8 +169,7 @@ struct l2tp_tunnel { u32 peer_tunnel_id; int version; /* 2=>L2TPv2, 3=>L2TPv3 */ - char name[20]; /* for logging */ - int debug; /* bitmask of debug message categories */ + char name[L2TP_TUNNEL_NAME_MAX]; /* for logging */ enum l2tp_encap_type encap; struct l2tp_stats stats; @@ -337,19 +335,6 @@ static inline int l2tp_v3_ensure_opt_in_linear(struct l2tp_session *session, str return 0; } -#define l2tp_printk(ptr, type, func, fmt, ...) \ -do { \ - if (((ptr)->debug) & (type)) \ - func(fmt, ##__VA_ARGS__); \ -} while (0) - -#define l2tp_warn(ptr, type, fmt, ...) \ - l2tp_printk(ptr, type, pr_warn, fmt, ##__VA_ARGS__) -#define l2tp_info(ptr, type, fmt, ...) \ - l2tp_printk(ptr, type, pr_info, fmt, ##__VA_ARGS__) -#define l2tp_dbg(ptr, type, fmt, ...) \ - l2tp_printk(ptr, type, pr_debug, fmt, ##__VA_ARGS__) - #define MODULE_ALIAS_L2TP_PWTYPE(type) \ MODULE_ALIAS("net-l2tp-type-" __stringify(type)) diff --git a/net/l2tp/l2tp_debugfs.c b/net/l2tp/l2tp_debugfs.c index 96cb9601c21b..bca75bef8282 100644 --- a/net/l2tp/l2tp_debugfs.c +++ b/net/l2tp/l2tp_debugfs.c @@ -167,7 +167,7 @@ static void l2tp_dfs_seq_tunnel_show(struct seq_file *m, void *v) tunnel->sock ? refcount_read(&tunnel->sock->sk_refcnt) : 0, refcount_read(&tunnel->ref_count)); seq_printf(m, " %08x rx %ld/%ld/%ld rx %ld/%ld/%ld\n", - tunnel->debug, + 0, atomic_long_read(&tunnel->stats.tx_packets), atomic_long_read(&tunnel->stats.tx_bytes), atomic_long_read(&tunnel->stats.tx_errors), @@ -192,7 +192,7 @@ static void l2tp_dfs_seq_session_show(struct seq_file *m, void *v) session->recv_seq ? 'R' : '-', session->send_seq ? 'S' : '-', session->lns_mode ? "LNS" : "LAC", - session->debug, + 0, jiffies_to_msecs(session->reorder_timeout)); seq_printf(m, " offset 0 l2specific %hu/%hu\n", session->l2specific_type, l2tp_get_l2specific_len(session)); diff --git a/net/l2tp/l2tp_eth.c b/net/l2tp/l2tp_eth.c index 7ed2b4eced94..657edad1263e 100644 --- a/net/l2tp/l2tp_eth.c +++ b/net/l2tp/l2tp_eth.c @@ -128,17 +128,6 @@ static void l2tp_eth_dev_recv(struct l2tp_session *session, struct sk_buff *skb, struct net_device *dev; struct l2tp_eth *priv; - if (session->debug & L2TP_MSG_DATA) { - unsigned int length; - - length = min(32u, skb->len); - if (!pskb_may_pull(skb, length)) - goto error; - - pr_debug("%s: eth recv\n", session->name); - print_hex_dump_bytes("", DUMP_PREFIX_OFFSET, skb->data, length); - } - if (!pskb_may_pull(skb, ETH_HLEN)) goto error; diff --git a/net/l2tp/l2tp_ip.c b/net/l2tp/l2tp_ip.c index df2a35b5714a..7086d97f293c 100644 --- a/net/l2tp/l2tp_ip.c +++ b/net/l2tp/l2tp_ip.c @@ -118,7 +118,6 @@ static int l2tp_ip_recv(struct sk_buff *skb) struct l2tp_session *session; struct l2tp_tunnel *tunnel = NULL; struct iphdr *iph; - int length; if (!pskb_may_pull(skb, 4)) goto discard; @@ -147,20 +146,6 @@ static int l2tp_ip_recv(struct sk_buff *skb) if (!tunnel) goto discard_sess; - /* Trace packet contents, if enabled */ - if (tunnel->debug & L2TP_MSG_DATA) { - length = min(32u, skb->len); - if (!pskb_may_pull(skb, length)) - goto discard_sess; - - /* Point to L2TP header */ - optr = skb->data; - ptr = skb->data; - ptr += 4; - pr_debug("%s: ip recv\n", tunnel->name); - print_hex_dump_bytes("", DUMP_PREFIX_OFFSET, ptr, length); - } - if (l2tp_v3_ensure_opt_in_linear(session, skb, &ptr, &optr)) goto discard_sess; diff --git a/net/l2tp/l2tp_ip6.c b/net/l2tp/l2tp_ip6.c index bc757bc7e264..409ea8927f6c 100644 --- a/net/l2tp/l2tp_ip6.c +++ b/net/l2tp/l2tp_ip6.c @@ -131,7 +131,6 @@ static int l2tp_ip6_recv(struct sk_buff *skb) struct l2tp_session *session; struct l2tp_tunnel *tunnel = NULL; struct ipv6hdr *iph; - int length; if (!pskb_may_pull(skb, 4)) goto discard; @@ -160,20 +159,6 @@ static int l2tp_ip6_recv(struct sk_buff *skb) if (!tunnel) goto discard_sess; - /* Trace packet contents, if enabled */ - if (tunnel->debug & L2TP_MSG_DATA) { - length = min(32u, skb->len); - if (!pskb_may_pull(skb, length)) - goto discard_sess; - - /* Point to L2TP header */ - optr = skb->data; - ptr = skb->data; - ptr += 4; - pr_debug("%s: ip recv\n", tunnel->name); - print_hex_dump_bytes("", DUMP_PREFIX_OFFSET, ptr, length); - } - if (l2tp_v3_ensure_opt_in_linear(session, skb, &ptr, &optr)) goto discard_sess; diff --git a/net/l2tp/l2tp_netlink.c b/net/l2tp/l2tp_netlink.c index def78eebca4c..31a1e27eab20 100644 --- a/net/l2tp/l2tp_netlink.c +++ b/net/l2tp/l2tp_netlink.c @@ -229,9 +229,6 @@ static int l2tp_nl_cmd_tunnel_create(struct sk_buff *skb, struct genl_info *info goto out; } - if (attrs[L2TP_ATTR_DEBUG]) - cfg.debug = nla_get_u32(attrs[L2TP_ATTR_DEBUG]); - ret = -EINVAL; switch (cfg.encap) { case L2TP_ENCAPTYPE_UDP: @@ -307,9 +304,6 @@ static int l2tp_nl_cmd_tunnel_modify(struct sk_buff *skb, struct genl_info *info goto out; } - if (info->attrs[L2TP_ATTR_DEBUG]) - tunnel->debug = nla_get_u32(info->attrs[L2TP_ATTR_DEBUG]); - ret = l2tp_tunnel_notify(&l2tp_nl_family, info, tunnel, L2TP_CMD_TUNNEL_MODIFY); @@ -400,7 +394,7 @@ static int l2tp_nl_tunnel_send(struct sk_buff *skb, u32 portid, u32 seq, int fla if (nla_put_u8(skb, L2TP_ATTR_PROTO_VERSION, tunnel->version) || nla_put_u32(skb, L2TP_ATTR_CONN_ID, tunnel->tunnel_id) || nla_put_u32(skb, L2TP_ATTR_PEER_CONN_ID, tunnel->peer_tunnel_id) || - nla_put_u32(skb, L2TP_ATTR_DEBUG, tunnel->debug) || + nla_put_u32(skb, L2TP_ATTR_DEBUG, 0) || nla_put_u16(skb, L2TP_ATTR_ENCAP_TYPE, tunnel->encap)) goto nla_put_failure; @@ -605,9 +599,6 @@ static int l2tp_nl_cmd_session_create(struct sk_buff *skb, struct genl_info *inf cfg.ifname = nla_data(info->attrs[L2TP_ATTR_IFNAME]); } - if (info->attrs[L2TP_ATTR_DEBUG]) - cfg.debug = nla_get_u32(info->attrs[L2TP_ATTR_DEBUG]); - if (info->attrs[L2TP_ATTR_RECV_SEQ]) cfg.recv_seq = nla_get_u8(info->attrs[L2TP_ATTR_RECV_SEQ]); @@ -689,9 +680,6 @@ static int l2tp_nl_cmd_session_modify(struct sk_buff *skb, struct genl_info *inf goto out; } - if (info->attrs[L2TP_ATTR_DEBUG]) - session->debug = nla_get_u32(info->attrs[L2TP_ATTR_DEBUG]); - if (info->attrs[L2TP_ATTR_RECV_SEQ]) session->recv_seq = nla_get_u8(info->attrs[L2TP_ATTR_RECV_SEQ]); @@ -730,7 +718,7 @@ static int l2tp_nl_session_send(struct sk_buff *skb, u32 portid, u32 seq, int fl nla_put_u32(skb, L2TP_ATTR_SESSION_ID, session->session_id) || nla_put_u32(skb, L2TP_ATTR_PEER_CONN_ID, tunnel->peer_tunnel_id) || nla_put_u32(skb, L2TP_ATTR_PEER_SESSION_ID, session->peer_session_id) || - nla_put_u32(skb, L2TP_ATTR_DEBUG, session->debug) || + nla_put_u32(skb, L2TP_ATTR_DEBUG, 0) || nla_put_u16(skb, L2TP_ATTR_PW_TYPE, session->pwtype)) goto nla_put_failure; diff --git a/net/l2tp/l2tp_ppp.c b/net/l2tp/l2tp_ppp.c index 13c3153b40d6..450637ffa557 100644 --- a/net/l2tp/l2tp_ppp.c +++ b/net/l2tp/l2tp_ppp.c @@ -237,17 +237,9 @@ static void pppol2tp_recv(struct l2tp_session *session, struct sk_buff *skb, int if (sk->sk_state & PPPOX_BOUND) { struct pppox_sock *po; - l2tp_dbg(session, L2TP_MSG_DATA, - "%s: recv %d byte data frame, passing to ppp\n", - session->name, data_len); - po = pppox_sk(sk); ppp_input(&po->chan, skb); } else { - l2tp_dbg(session, L2TP_MSG_DATA, - "%s: recv %d byte data frame, passing to L2TP socket\n", - session->name, data_len); - if (sock_queue_rcv_skb(sk, skb) < 0) { atomic_long_inc(&session->stats.rx_errors); kfree_skb(skb); @@ -259,7 +251,7 @@ static void pppol2tp_recv(struct l2tp_session *session, struct sk_buff *skb, int no_sock: rcu_read_unlock(); - l2tp_info(session, L2TP_MSG_DATA, "%s: no socket\n", session->name); + pr_warn_ratelimited("%s: no socket in recv\n", session->name); kfree_skb(skb); } @@ -710,7 +702,6 @@ static int pppol2tp_connect(struct socket *sock, struct sockaddr *uservaddr, if (!tunnel) { struct l2tp_tunnel_cfg tcfg = { .encap = L2TP_ENCAPTYPE_UDP, - .debug = 0, }; /* Prevent l2tp_tunnel_register() from trying to set up @@ -840,8 +831,6 @@ out_no_ppp: drop_refcnt = false; sk->sk_state = PPPOX_CONNECTED; - l2tp_info(session, L2TP_MSG_CONTROL, "%s: created\n", - session->name); end: if (error) { @@ -1157,9 +1146,7 @@ static int pppol2tp_tunnel_setsockopt(struct sock *sk, switch (optname) { case PPPOL2TP_SO_DEBUG: - tunnel->debug = val; - l2tp_info(tunnel, L2TP_MSG_CONTROL, "%s: set debug=%x\n", - tunnel->name, tunnel->debug); + /* Tunnel debug flags option is deprecated */ break; default: @@ -1185,9 +1172,6 @@ static int pppol2tp_session_setsockopt(struct sock *sk, break; } session->recv_seq = !!val; - l2tp_info(session, L2TP_MSG_CONTROL, - "%s: set recv_seq=%d\n", - session->name, session->recv_seq); break; case PPPOL2TP_SO_SENDSEQ: @@ -1203,9 +1187,6 @@ static int pppol2tp_session_setsockopt(struct sock *sk, PPPOL2TP_L2TP_HDR_SIZE_NOSEQ; } l2tp_session_set_header_len(session, session->tunnel->version); - l2tp_info(session, L2TP_MSG_CONTROL, - "%s: set send_seq=%d\n", - session->name, session->send_seq); break; case PPPOL2TP_SO_LNSMODE: @@ -1214,22 +1195,14 @@ static int pppol2tp_session_setsockopt(struct sock *sk, break; } session->lns_mode = !!val; - l2tp_info(session, L2TP_MSG_CONTROL, - "%s: set lns_mode=%d\n", - session->name, session->lns_mode); break; case PPPOL2TP_SO_DEBUG: - session->debug = val; - l2tp_info(session, L2TP_MSG_CONTROL, "%s: set debug=%x\n", - session->name, session->debug); + /* Session debug flags option is deprecated */ break; case PPPOL2TP_SO_REORDERTO: session->reorder_timeout = msecs_to_jiffies(val); - l2tp_info(session, L2TP_MSG_CONTROL, - "%s: set reorder_timeout=%d\n", - session->name, session->reorder_timeout); break; default: @@ -1297,9 +1270,8 @@ static int pppol2tp_tunnel_getsockopt(struct sock *sk, switch (optname) { case PPPOL2TP_SO_DEBUG: - *val = tunnel->debug; - l2tp_info(tunnel, L2TP_MSG_CONTROL, "%s: get debug=%x\n", - tunnel->name, tunnel->debug); + /* Tunnel debug flags option is deprecated */ + *val = 0; break; default: @@ -1321,32 +1293,23 @@ static int pppol2tp_session_getsockopt(struct sock *sk, switch (optname) { case PPPOL2TP_SO_RECVSEQ: *val = session->recv_seq; - l2tp_info(session, L2TP_MSG_CONTROL, - "%s: get recv_seq=%d\n", session->name, *val); break; case PPPOL2TP_SO_SENDSEQ: *val = session->send_seq; - l2tp_info(session, L2TP_MSG_CONTROL, - "%s: get send_seq=%d\n", session->name, *val); break; case PPPOL2TP_SO_LNSMODE: *val = session->lns_mode; - l2tp_info(session, L2TP_MSG_CONTROL, - "%s: get lns_mode=%d\n", session->name, *val); break; case PPPOL2TP_SO_DEBUG: - *val = session->debug; - l2tp_info(session, L2TP_MSG_CONTROL, "%s: get debug=%d\n", - session->name, *val); + /* Session debug flags option is deprecated */ + *val = 0; break; case PPPOL2TP_SO_REORDERTO: *val = (int)jiffies_to_msecs(session->reorder_timeout); - l2tp_info(session, L2TP_MSG_CONTROL, - "%s: get reorder_timeout=%d\n", session->name, *val); break; default: @@ -1534,7 +1497,7 @@ static void pppol2tp_seq_tunnel_show(struct seq_file *m, void *v) (tunnel == tunnel->sock->sk_user_data) ? 'Y' : 'N', refcount_read(&tunnel->ref_count) - 1); seq_printf(m, " %08x %ld/%ld/%ld %ld/%ld/%ld\n", - tunnel->debug, + 0, atomic_long_read(&tunnel->stats.tx_packets), atomic_long_read(&tunnel->stats.tx_bytes), atomic_long_read(&tunnel->stats.tx_errors), @@ -1580,7 +1543,7 @@ static void pppol2tp_seq_session_show(struct seq_file *m, void *v) session->recv_seq ? 'R' : '-', session->send_seq ? 'S' : '-', session->lns_mode ? "LNS" : "LAC", - session->debug, + 0, jiffies_to_msecs(session->reorder_timeout)); seq_printf(m, " %hu/%hu %ld/%ld/%ld %ld/%ld/%ld\n", session->nr, session->ns, diff --git a/net/l2tp/trace.h b/net/l2tp/trace.h new file mode 100644 index 000000000000..8596eaa12a2e --- /dev/null +++ b/net/l2tp/trace.h @@ -0,0 +1,211 @@ +/* SPDX-License-Identifier: GPL-2.0-only */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM l2tp + +#if !defined(_TRACE_L2TP_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_L2TP_H + +#include <linux/tracepoint.h> +#include <linux/l2tp.h> +#include "l2tp_core.h" + +#define encap_type_name(e) { L2TP_ENCAPTYPE_##e, #e } +#define show_encap_type_name(val) \ + __print_symbolic(val, \ + encap_type_name(UDP), \ + encap_type_name(IP)) + +#define pw_type_name(p) { L2TP_PWTYPE_##p, #p } +#define show_pw_type_name(val) \ + __print_symbolic(val, \ + pw_type_name(ETH_VLAN), \ + pw_type_name(ETH), \ + pw_type_name(PPP), \ + pw_type_name(PPP_AC), \ + pw_type_name(IP)) + +DECLARE_EVENT_CLASS(tunnel_only_evt, + TP_PROTO(struct l2tp_tunnel *tunnel), + TP_ARGS(tunnel), + TP_STRUCT__entry( + __array(char, name, L2TP_TUNNEL_NAME_MAX) + ), + TP_fast_assign( + memcpy(__entry->name, tunnel->name, L2TP_TUNNEL_NAME_MAX); + ), + TP_printk("%s", __entry->name) +); + +DECLARE_EVENT_CLASS(session_only_evt, + TP_PROTO(struct l2tp_session *session), + TP_ARGS(session), + TP_STRUCT__entry( + __array(char, name, L2TP_SESSION_NAME_MAX) + ), + TP_fast_assign( + memcpy(__entry->name, session->name, L2TP_SESSION_NAME_MAX); + ), + TP_printk("%s", __entry->name) +); + +TRACE_EVENT(register_tunnel, + TP_PROTO(struct l2tp_tunnel *tunnel), + TP_ARGS(tunnel), + TP_STRUCT__entry( + __array(char, name, L2TP_TUNNEL_NAME_MAX) + __field(int, fd) + __field(u32, tid) + __field(u32, ptid) + __field(int, version) + __field(enum l2tp_encap_type, encap) + ), + TP_fast_assign( + memcpy(__entry->name, tunnel->name, L2TP_TUNNEL_NAME_MAX); + __entry->fd = tunnel->fd; + __entry->tid = tunnel->tunnel_id; + __entry->ptid = tunnel->peer_tunnel_id; + __entry->version = tunnel->version; + __entry->encap = tunnel->encap; + ), + TP_printk("%s: type=%s encap=%s version=L2TPv%d tid=%u ptid=%u fd=%d", + __entry->name, + __entry->fd > 0 ? "managed" : "unmanaged", + show_encap_type_name(__entry->encap), + __entry->version, + __entry->tid, + __entry->ptid, + __entry->fd) +); + +DEFINE_EVENT(tunnel_only_evt, delete_tunnel, + TP_PROTO(struct l2tp_tunnel *tunnel), + TP_ARGS(tunnel) +); + +DEFINE_EVENT(tunnel_only_evt, free_tunnel, + TP_PROTO(struct l2tp_tunnel *tunnel), + TP_ARGS(tunnel) +); + +TRACE_EVENT(register_session, + TP_PROTO(struct l2tp_session *session), + TP_ARGS(session), + TP_STRUCT__entry( + __array(char, name, L2TP_SESSION_NAME_MAX) + __field(u32, tid) + __field(u32, ptid) + __field(u32, sid) + __field(u32, psid) + __field(enum l2tp_pwtype, pwtype) + ), + TP_fast_assign( + memcpy(__entry->name, session->name, L2TP_SESSION_NAME_MAX); + __entry->tid = session->tunnel ? session->tunnel->tunnel_id : 0; + __entry->ptid = session->tunnel ? session->tunnel->peer_tunnel_id : 0; + __entry->sid = session->session_id; + __entry->psid = session->peer_session_id; + __entry->pwtype = session->pwtype; + ), + TP_printk("%s: pseudowire=%s sid=%u psid=%u tid=%u ptid=%u", + __entry->name, + show_pw_type_name(__entry->pwtype), + __entry->sid, + __entry->psid, + __entry->sid, + __entry->psid) +); + +DEFINE_EVENT(session_only_evt, delete_session, + TP_PROTO(struct l2tp_session *session), + TP_ARGS(session) +); + +DEFINE_EVENT(session_only_evt, free_session, + TP_PROTO(struct l2tp_session *session), + TP_ARGS(session) +); + +DEFINE_EVENT(session_only_evt, session_seqnum_lns_enable, + TP_PROTO(struct l2tp_session *session), + TP_ARGS(session) +); + +DEFINE_EVENT(session_only_evt, session_seqnum_lns_disable, + TP_PROTO(struct l2tp_session *session), + TP_ARGS(session) +); + +DECLARE_EVENT_CLASS(session_seqnum_evt, + TP_PROTO(struct l2tp_session *session), + TP_ARGS(session), + TP_STRUCT__entry( + __array(char, name, L2TP_SESSION_NAME_MAX) + __field(u32, ns) + __field(u32, nr) + ), + TP_fast_assign( + memcpy(__entry->name, session->name, L2TP_SESSION_NAME_MAX); + __entry->ns = session->ns; + __entry->nr = session->nr; + ), + TP_printk("%s: ns=%u nr=%u", + __entry->name, + __entry->ns, + __entry->nr) +); + +DEFINE_EVENT(session_seqnum_evt, session_seqnum_update, + TP_PROTO(struct l2tp_session *session), + TP_ARGS(session) +); + +DEFINE_EVENT(session_seqnum_evt, session_seqnum_reset, + TP_PROTO(struct l2tp_session *session), + TP_ARGS(session) +); + +DECLARE_EVENT_CLASS(session_pkt_discard_evt, + TP_PROTO(struct l2tp_session *session, u32 pkt_ns), + TP_ARGS(session, pkt_ns), + TP_STRUCT__entry( + __array(char, name, L2TP_SESSION_NAME_MAX) + __field(u32, pkt_ns) + __field(u32, my_nr) + __field(u32, reorder_q_len) + ), + TP_fast_assign( + memcpy(__entry->name, session->name, L2TP_SESSION_NAME_MAX); + __entry->pkt_ns = pkt_ns, + __entry->my_nr = session->nr; + __entry->reorder_q_len = skb_queue_len(&session->reorder_q); + ), + TP_printk("%s: pkt_ns=%u my_nr=%u reorder_q_len=%u", + __entry->name, + __entry->pkt_ns, + __entry->my_nr, + __entry->reorder_q_len) +); + +DEFINE_EVENT(session_pkt_discard_evt, session_pkt_expired, + TP_PROTO(struct l2tp_session *session, u32 pkt_ns), + TP_ARGS(session, pkt_ns) +); + +DEFINE_EVENT(session_pkt_discard_evt, session_pkt_outside_rx_window, + TP_PROTO(struct l2tp_session *session, u32 pkt_ns), + TP_ARGS(session, pkt_ns) +); + +DEFINE_EVENT(session_pkt_discard_evt, session_pkt_oos, + TP_PROTO(struct l2tp_session *session, u32 pkt_ns), + TP_ARGS(session, pkt_ns) +); + +#endif /* _TRACE_L2TP_H */ + +/* This part must be outside protection */ +#undef TRACE_INCLUDE_PATH +#define TRACE_INCLUDE_PATH . +#undef TRACE_INCLUDE_FILE +#define TRACE_INCLUDE_FILE trace +#include <trace/define_trace.h> |