net: sctp: rework debugging framework to use pr_debug and friends
We should get rid of all own SCTP debug printk macros and use the ones
that the kernel offers anyway instead. This makes the code more readable
and conform to the kernel code, and offers all the features of dynamic
debbuging that pr_debug() et al has, such as only turning on/off portions
of debug messages at runtime through debugfs. The runtime cost of having
CONFIG_DYNAMIC_DEBUG enabled, but none of the debug statements printing,
is negligible [1]. If kernel debugging is completly turned off, then these
statements will also compile into "empty" functions.
While we're at it, we also need to change the Kconfig option as it /now/
only refers to the ifdef'ed code portions in outqueue.c that enable further
debugging/tracing of SCTP transaction fields. Also, since SCTP_ASSERT code
was enabled with this Kconfig option and has now been removed, we
transform those code parts into WARNs resp. where appropriate BUG_ONs so
that those bugs can be more easily detected as probably not many people
have SCTP debugging permanently turned on.
To turn on all SCTP debugging, the following steps are needed:
# mount -t debugfs none /sys/kernel/debug
# echo -n 'module sctp +p' > /sys/kernel/debug/dynamic_debug/control
This can be done more fine-grained on a per file, per line basis and others
as described in [2].
[1] https://www.kernel.org/doc/ols/2009/ols2009-pages-39-46.pdf
[2] Documentation/dynamic-debug-howto.txt
Signed-off-by: Daniel Borkmann <dborkman@redhat.com>
Signed-off-by: David S. Miller <davem@davemloft.net>
diff --git a/net/sctp/socket.c b/net/sctp/socket.c
index 66fcdcf..d5c6a28 100644
--- a/net/sctp/socket.c
+++ b/net/sctp/socket.c
@@ -281,8 +281,8 @@
sctp_lock_sock(sk);
- SCTP_DEBUG_PRINTK("sctp_bind(sk: %p, addr: %p, addr_len: %d)\n",
- sk, addr, addr_len);
+ pr_debug("%s: sk:%p, addr:%p, addr_len:%d\n", __func__, sk,
+ addr, addr_len);
/* Disallow binding twice. */
if (!sctp_sk(sk)->ep->base.bind_addr.port)
@@ -342,19 +342,15 @@
/* Common sockaddr verification. */
af = sctp_sockaddr_af(sp, addr, len);
if (!af) {
- SCTP_DEBUG_PRINTK("sctp_do_bind(sk: %p, newaddr: %p, len: %d) EINVAL\n",
- sk, addr, len);
+ pr_debug("%s: sk:%p, newaddr:%p, len:%d EINVAL\n",
+ __func__, sk, addr, len);
return -EINVAL;
}
snum = ntohs(addr->v4.sin_port);
- SCTP_DEBUG_PRINTK_IPADDR("sctp_do_bind(sk: %p, new addr: ",
- ", port: %d, new port: %d, len: %d)\n",
- sk,
- addr,
- bp->port, snum,
- len);
+ pr_debug("%s: sk:%p, new addr:%pISc, port:%d, new port:%d, len:%d\n",
+ __func__, sk, &addr->sa, bp->port, snum, len);
/* PF specific bind() address verification. */
if (!sp->pf->bind_verify(sp, addr))
@@ -368,9 +364,8 @@
if (!snum)
snum = bp->port;
else if (snum != bp->port) {
- SCTP_DEBUG_PRINTK("sctp_do_bind:"
- " New port %d does not match existing port "
- "%d.\n", snum, bp->port);
+ pr_debug("%s: new port %d doesn't match existing port "
+ "%d\n", __func__, snum, bp->port);
return -EINVAL;
}
}
@@ -468,8 +463,8 @@
struct sockaddr *sa_addr;
struct sctp_af *af;
- SCTP_DEBUG_PRINTK("sctp_bindx_add (sk: %p, addrs: %p, addrcnt: %d)\n",
- sk, addrs, addrcnt);
+ pr_debug("%s: sk:%p, addrs:%p, addrcnt:%d\n", __func__, sk,
+ addrs, addrcnt);
addr_buf = addrs;
for (cnt = 0; cnt < addrcnt; cnt++) {
@@ -535,11 +530,10 @@
sp = sctp_sk(sk);
ep = sp->ep;
- SCTP_DEBUG_PRINTK("%s: (sk: %p, addrs: %p, addrcnt: %d)\n",
- __func__, sk, addrs, addrcnt);
+ pr_debug("%s: sk:%p, addrs:%p, addrcnt:%d\n",
+ __func__, sk, addrs, addrcnt);
list_for_each_entry(asoc, &ep->asocs, asocs) {
-
if (!asoc->peer.asconf_capable)
continue;
@@ -646,8 +640,8 @@
union sctp_addr *sa_addr;
struct sctp_af *af;
- SCTP_DEBUG_PRINTK("sctp_bindx_rem (sk: %p, addrs: %p, addrcnt: %d)\n",
- sk, addrs, addrcnt);
+ pr_debug("%s: sk:%p, addrs:%p, addrcnt:%d\n",
+ __func__, sk, addrs, addrcnt);
addr_buf = addrs;
for (cnt = 0; cnt < addrcnt; cnt++) {
@@ -740,8 +734,8 @@
sp = sctp_sk(sk);
ep = sp->ep;
- SCTP_DEBUG_PRINTK("%s: (sk: %p, addrs: %p, addrcnt: %d)\n",
- __func__, sk, addrs, addrcnt);
+ pr_debug("%s: sk:%p, addrs:%p, addrcnt:%d\n",
+ __func__, sk, addrs, addrcnt);
list_for_each_entry(asoc, &ep->asocs, asocs) {
@@ -808,9 +802,11 @@
sin6 = (struct sockaddr_in6 *)addrs;
asoc->asconf_addr_del_pending->v6.sin6_addr = sin6->sin6_addr;
}
- SCTP_DEBUG_PRINTK_IPADDR("send_asconf_del_ip: keep the last address asoc: %p ",
- " at %p\n", asoc, asoc->asconf_addr_del_pending,
- asoc->asconf_addr_del_pending);
+
+ pr_debug("%s: keep the last address asoc:%p %pISc at %p\n",
+ __func__, asoc, &asoc->asconf_addr_del_pending->sa,
+ asoc->asconf_addr_del_pending);
+
asoc->src_out_of_asoc_ok = 1;
stored = 1;
goto skip_mkasconf;
@@ -972,8 +968,8 @@
void *addr_buf;
struct sctp_af *af;
- SCTP_DEBUG_PRINTK("sctp_setsockopt_bindx: sk %p addrs %p"
- " addrs_size %d opt %d\n", sk, addrs, addrs_size, op);
+ pr_debug("%s: sk:%p addrs:%p addrs_size:%d opt:%d\n",
+ __func__, sk, addrs, addrs_size, op);
if (unlikely(addrs_size <= 0))
return -EINVAL;
@@ -1231,10 +1227,9 @@
asoc = NULL;
out_free:
+ pr_debug("%s: took out_free path with asoc:%p kaddrs:%p err:%d\n",
+ __func__, asoc, kaddrs, err);
- SCTP_DEBUG_PRINTK("About to exit __sctp_connect() free asoc: %p"
- " kaddrs: %p err: %d\n",
- asoc, kaddrs, err);
if (asoc) {
/* sctp_primitive_ASSOCIATE may have added this association
* To the hash table, try to unhash it, just in case, its a noop
@@ -1316,8 +1311,8 @@
int err = 0;
struct sockaddr *kaddrs;
- SCTP_DEBUG_PRINTK("%s - sk %p addrs %p addrs_size %d\n",
- __func__, sk, addrs, addrs_size);
+ pr_debug("%s: sk:%p addrs:%p addrs_size:%d\n",
+ __func__, sk, addrs, addrs_size);
if (unlikely(addrs_size <= 0))
return -EINVAL;
@@ -1468,7 +1463,7 @@
struct list_head *pos, *temp;
unsigned int data_was_unread;
- SCTP_DEBUG_PRINTK("sctp_close(sk: 0x%p, timeout:%ld)\n", sk, timeout);
+ pr_debug("%s: sk:%p, timeout:%ld\n", __func__, sk, timeout);
sctp_lock_sock(sk);
sk->sk_shutdown = SHUTDOWN_MASK;
@@ -1594,14 +1589,12 @@
struct sctp_datamsg *datamsg;
int msg_flags = msg->msg_flags;
- SCTP_DEBUG_PRINTK("sctp_sendmsg(sk: %p, msg: %p, msg_len: %zu)\n",
- sk, msg, msg_len);
-
err = 0;
sp = sctp_sk(sk);
ep = sp->ep;
- SCTP_DEBUG_PRINTK("Using endpoint: %p.\n", ep);
+ pr_debug("%s: sk:%p, msg:%p, msg_len:%zu ep:%p\n", __func__, sk,
+ msg, msg_len, ep);
/* We cannot send a message over a TCP-style listening socket. */
if (sctp_style(sk, TCP) && sctp_sstate(sk, LISTENING)) {
@@ -1611,9 +1604,8 @@
/* Parse out the SCTP CMSGs. */
err = sctp_msghdr_parse(msg, &cmsgs);
-
if (err) {
- SCTP_DEBUG_PRINTK("msghdr parse err = %x\n", err);
+ pr_debug("%s: msghdr parse err:%x\n", __func__, err);
goto out_nounlock;
}
@@ -1645,8 +1637,8 @@
associd = sinfo->sinfo_assoc_id;
}
- SCTP_DEBUG_PRINTK("msg_len: %zu, sinfo_flags: 0x%x\n",
- msg_len, sinfo_flags);
+ pr_debug("%s: msg_len:%zu, sinfo_flags:0x%x\n", __func__,
+ msg_len, sinfo_flags);
/* SCTP_EOF or SCTP_ABORT cannot be set on a TCP-style socket. */
if (sctp_style(sk, TCP) && (sinfo_flags & (SCTP_EOF | SCTP_ABORT))) {
@@ -1675,7 +1667,7 @@
transport = NULL;
- SCTP_DEBUG_PRINTK("About to look up association.\n");
+ pr_debug("%s: about to look up association\n", __func__);
sctp_lock_sock(sk);
@@ -1705,7 +1697,7 @@
}
if (asoc) {
- SCTP_DEBUG_PRINTK("Just looked up association: %p.\n", asoc);
+ pr_debug("%s: just looked up association:%p\n", __func__, asoc);
/* We cannot send a message on a TCP-style SCTP_SS_ESTABLISHED
* socket that has an association in CLOSED state. This can
@@ -1718,8 +1710,9 @@
}
if (sinfo_flags & SCTP_EOF) {
- SCTP_DEBUG_PRINTK("Shutting down association: %p\n",
- asoc);
+ pr_debug("%s: shutting down association:%p\n",
+ __func__, asoc);
+
sctp_primitive_SHUTDOWN(net, asoc, NULL);
err = 0;
goto out_unlock;
@@ -1732,7 +1725,9 @@
goto out_unlock;
}
- SCTP_DEBUG_PRINTK("Aborting association: %p\n", asoc);
+ pr_debug("%s: aborting association:%p\n",
+ __func__, asoc);
+
sctp_primitive_ABORT(net, asoc, chunk);
err = 0;
goto out_unlock;
@@ -1741,7 +1736,7 @@
/* Do we need to create the association? */
if (!asoc) {
- SCTP_DEBUG_PRINTK("There is no association yet.\n");
+ pr_debug("%s: there is no association yet\n", __func__);
if (sinfo_flags & (SCTP_EOF | SCTP_ABORT)) {
err = -EINVAL;
@@ -1840,7 +1835,7 @@
}
/* ASSERT: we have a valid association at this point. */
- SCTP_DEBUG_PRINTK("We have a valid association.\n");
+ pr_debug("%s: we have a valid association\n", __func__);
if (!sinfo) {
/* If the user didn't specify SNDRCVINFO, make up one with
@@ -1909,7 +1904,8 @@
err = sctp_primitive_ASSOCIATE(net, asoc, NULL);
if (err < 0)
goto out_free;
- SCTP_DEBUG_PRINTK("We associated primitively.\n");
+
+ pr_debug("%s: we associated primitively\n", __func__);
}
/* Break the message into multiple chunks of maximum size. */
@@ -1936,17 +1932,15 @@
*/
err = sctp_primitive_SEND(net, asoc, datamsg);
/* Did the lower layer accept the chunk? */
- if (err)
+ if (err) {
sctp_datamsg_free(datamsg);
- else
- sctp_datamsg_put(datamsg);
-
- SCTP_DEBUG_PRINTK("We sent primitively.\n");
-
- if (err)
goto out_free;
- else
- err = msg_len;
+ }
+
+ pr_debug("%s: we sent primitively\n", __func__);
+
+ sctp_datamsg_put(datamsg);
+ err = msg_len;
/* If we are already past ASSOCIATE, the lower
* layers are responsible for association cleanup.
@@ -2041,10 +2035,9 @@
int err = 0;
int skb_len;
- SCTP_DEBUG_PRINTK("sctp_recvmsg(%s: %p, %s: %p, %s: %zd, %s: %d, %s: "
- "0x%x, %s: %p)\n", "sk", sk, "msghdr", msg,
- "len", len, "knoblauch", noblock,
- "flags", flags, "addr_len", addr_len);
+ pr_debug("%s: sk:%p, msghdr:%p, len:%zd, noblock:%d, flags:0x%x, "
+ "addr_len:%p)\n", __func__, sk, msg, len, noblock, flags,
+ addr_len);
sctp_lock_sock(sk);
@@ -3086,7 +3079,7 @@
err = sctp_send_asconf(asoc, chunk);
- SCTP_DEBUG_PRINTK("We set peer primary addr primitively.\n");
+ pr_debug("%s: we set peer primary addr primitively\n", __func__);
return err;
}
@@ -3561,8 +3554,7 @@
{
int retval = 0;
- SCTP_DEBUG_PRINTK("sctp_setsockopt(sk: %p... optname: %d)\n",
- sk, optname);
+ pr_debug("%s: sk:%p, optname:%d\n", __func__, sk, optname);
/* I can hardly begin to describe how wrong this is. This is
* so broken as to be worse than useless. The API draft
@@ -3724,8 +3716,8 @@
sctp_lock_sock(sk);
- SCTP_DEBUG_PRINTK("%s - sk: %p, sockaddr: %p, addr_len: %d\n",
- __func__, sk, addr, addr_len);
+ pr_debug("%s: sk:%p, sockaddr:%p, addr_len:%d\n", __func__, sk,
+ addr, addr_len);
/* Validate addr_len before calling common connect/connectx routine. */
af = sctp_get_af_specific(addr->sa_family);
@@ -3855,7 +3847,7 @@
struct net *net = sock_net(sk);
struct sctp_sock *sp;
- SCTP_DEBUG_PRINTK("sctp_init_sock(sk: %p)\n", sk);
+ pr_debug("%s: sk:%p\n", __func__, sk);
sp = sctp_sk(sk);
@@ -3990,7 +3982,7 @@
{
struct sctp_sock *sp;
- SCTP_DEBUG_PRINTK("sctp_destroy_sock(sk: %p)\n", sk);
+ pr_debug("%s: sk:%p\n", __func__, sk);
/* Release our hold on the endpoint. */
sp = sctp_sk(sk);
@@ -4123,9 +4115,9 @@
goto out;
}
- SCTP_DEBUG_PRINTK("sctp_getsockopt_sctp_status(%d): %d %d %d\n",
- len, status.sstat_state, status.sstat_rwnd,
- status.sstat_assoc_id);
+ pr_debug("%s: len:%d, state:%d, rwnd:%d, assoc_id:%d\n",
+ __func__, len, status.sstat_state, status.sstat_rwnd,
+ status.sstat_assoc_id);
if (copy_to_user(optval, &status, len)) {
retval = -EFAULT;
@@ -4333,8 +4325,8 @@
return PTR_ERR(newfile);
}
- SCTP_DEBUG_PRINTK("%s: sk: %p newsk: %p sd: %d\n",
- __func__, sk, newsock->sk, retval);
+ pr_debug("%s: sk:%p, newsk:%p, sd:%d\n", __func__, sk, newsock->sk,
+ retval);
/* Return the fd mapped to the new socket. */
if (put_user(len, optlen)) {
@@ -4467,7 +4459,7 @@
trans = sctp_addr_id2transport(sk, ¶ms.spp_address,
params.spp_assoc_id);
if (!trans) {
- SCTP_DEBUG_PRINTK("Failed no transport\n");
+ pr_debug("%s: failed no transport\n", __func__);
return -EINVAL;
}
}
@@ -4478,7 +4470,7 @@
*/
asoc = sctp_id2assoc(sk, params.spp_assoc_id);
if (!asoc && params.spp_assoc_id && sctp_style(sk, UDP)) {
- SCTP_DEBUG_PRINTK("Failed no association\n");
+ pr_debug("%s: failed no association\n", __func__);
return -EINVAL;
}
@@ -5698,8 +5690,7 @@
if (put_user(len, optlen))
return -EFAULT;
- SCTP_DEBUG_PRINTK("sctp_getsockopt_assoc_stat(%d): %d\n",
- len, sas.sas_assoc_id);
+ pr_debug("%s: len:%d, assoc_id:%d\n", __func__, len, sas.sas_assoc_id);
if (copy_to_user(optval, &sas, len))
return -EFAULT;
@@ -5713,8 +5704,7 @@
int retval = 0;
int len;
- SCTP_DEBUG_PRINTK("sctp_getsockopt(sk: %p... optname: %d)\n",
- sk, optname);
+ pr_debug("%s: sk:%p, optname:%d\n", __func__, sk, optname);
/* I can hardly begin to describe how wrong this is. This is
* so broken as to be worse than useless. The API draft
@@ -5894,7 +5884,8 @@
snum = ntohs(addr->v4.sin_port);
- SCTP_DEBUG_PRINTK("sctp_get_port() begins, snum=%d\n", snum);
+ pr_debug("%s: begins, snum:%d\n", __func__, snum);
+
sctp_local_bh_disable();
if (snum == 0) {
@@ -5960,7 +5951,8 @@
int reuse = sk->sk_reuse;
struct sock *sk2;
- SCTP_DEBUG_PRINTK("sctp_get_port() found a possible match\n");
+ pr_debug("%s: found a possible match\n", __func__);
+
if (pp->fastreuse && sk->sk_reuse &&
sk->sk_state != SCTP_SS_LISTENING)
goto success;
@@ -5990,7 +5982,8 @@
goto fail_unlock;
}
}
- SCTP_DEBUG_PRINTK("sctp_get_port(): Found a match\n");
+
+ pr_debug("%s: found a match\n", __func__);
}
pp_not_found:
/* If there was a hash table miss, create a new port. */
@@ -6479,8 +6472,8 @@
timeo = sock_rcvtimeo(sk, noblock);
- SCTP_DEBUG_PRINTK("Timeout: timeo: %ld, MAX: %ld.\n",
- timeo, MAX_SCHEDULE_TIMEOUT);
+ pr_debug("%s: timeo:%ld, max:%ld\n", __func__, timeo,
+ MAX_SCHEDULE_TIMEOUT);
do {
/* Again only user level code calls this function,
@@ -6611,8 +6604,8 @@
long current_timeo = *timeo_p;
DEFINE_WAIT(wait);
- SCTP_DEBUG_PRINTK("wait_for_sndbuf: asoc=%p, timeo=%ld, msg_len=%zu\n",
- asoc, (long)(*timeo_p), msg_len);
+ pr_debug("%s: asoc:%p, timeo:%ld, msg_len:%zu\n", __func__, asoc,
+ *timeo_p, msg_len);
/* Increment the association's refcnt. */
sctp_association_hold(asoc);
@@ -6718,8 +6711,7 @@
long current_timeo = *timeo_p;
DEFINE_WAIT(wait);
- SCTP_DEBUG_PRINTK("%s: asoc=%p, timeo=%ld\n", __func__, asoc,
- (long)(*timeo_p));
+ pr_debug("%s: asoc:%p, timeo:%ld\n", __func__, asoc, *timeo_p);
/* Increment the association's refcnt. */
sctp_association_hold(asoc);
