Linux kernel mirror (for testing) git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
kernel os linux

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>

authored by

Daniel Borkmann and committed by
David S. Miller
bb33381d 10679643

+382 -483
-75
include/net/sctp/sctp.h
··· 83 83 #include <net/sctp/structs.h> 84 84 #include <net/sctp/constants.h> 85 85 86 - 87 - /* Set SCTP_DEBUG flag via config if not already set. */ 88 - #ifndef SCTP_DEBUG 89 - #ifdef CONFIG_SCTP_DBG_MSG 90 - #define SCTP_DEBUG 1 91 - #else 92 - #define SCTP_DEBUG 0 93 - #endif /* CONFIG_SCTP_DBG */ 94 - #endif /* SCTP_DEBUG */ 95 - 96 86 #ifdef CONFIG_IP_SCTP_MODULE 97 87 #define SCTP_PROTOSW_FLAG 0 98 88 #else /* static! */ ··· 259 269 trans->af_specific->sockaddr_len); 260 270 } 261 271 } 262 - 263 - /* Print debugging messages. */ 264 - #if SCTP_DEBUG 265 - extern int sctp_debug_flag; 266 - #define SCTP_DEBUG_PRINTK(fmt, args...) \ 267 - do { \ 268 - if (sctp_debug_flag) \ 269 - printk(KERN_DEBUG pr_fmt(fmt), ##args); \ 270 - } while (0) 271 - #define SCTP_DEBUG_PRINTK_CONT(fmt, args...) \ 272 - do { \ 273 - if (sctp_debug_flag) \ 274 - pr_cont(fmt, ##args); \ 275 - } while (0) 276 - #define SCTP_DEBUG_PRINTK_IPADDR(fmt_lead, fmt_trail, \ 277 - args_lead, addr, args_trail...) \ 278 - do { \ 279 - const union sctp_addr *_addr = (addr); \ 280 - if (sctp_debug_flag) { \ 281 - if (_addr->sa.sa_family == AF_INET6) { \ 282 - printk(KERN_DEBUG \ 283 - pr_fmt(fmt_lead "%pI6" fmt_trail), \ 284 - args_lead, \ 285 - &_addr->v6.sin6_addr, \ 286 - args_trail); \ 287 - } else { \ 288 - printk(KERN_DEBUG \ 289 - pr_fmt(fmt_lead "%pI4" fmt_trail), \ 290 - args_lead, \ 291 - &_addr->v4.sin_addr.s_addr, \ 292 - args_trail); \ 293 - } \ 294 - } \ 295 - } while (0) 296 - #define SCTP_ENABLE_DEBUG { sctp_debug_flag = 1; } 297 - #define SCTP_DISABLE_DEBUG { sctp_debug_flag = 0; } 298 - 299 - #define SCTP_ASSERT(expr, str, func) \ 300 - if (!(expr)) { \ 301 - SCTP_DEBUG_PRINTK("Assertion Failed: %s(%s) at %s:%s:%d\n", \ 302 - str, (#expr), __FILE__, __func__, __LINE__); \ 303 - func; \ 304 - } 305 - 306 - #else /* SCTP_DEBUG */ 307 - 308 - #define SCTP_DEBUG_PRINTK(whatever...) 309 - #define SCTP_DEBUG_PRINTK_CONT(fmt, args...) 310 - #define SCTP_DEBUG_PRINTK_IPADDR(whatever...) 311 - #define SCTP_ENABLE_DEBUG 312 - #define SCTP_DISABLE_DEBUG 313 - #define SCTP_ASSERT(expr, str, func) 314 - 315 - #endif /* SCTP_DEBUG */ 316 - 317 272 318 273 /* 319 274 * Macros for keeping a global reference of object allocations. ··· 530 595 default: 531 596 return 0; 532 597 } 533 - } 534 - 535 - /* Perform some sanity checks. */ 536 - static inline int sctp_sanity_check(void) 537 - { 538 - SCTP_ASSERT(sizeof(struct sctp_ulpevent) <= 539 - sizeof(((struct sk_buff *)0)->cb), 540 - "SCTP: ulpevent does not fit in skb!\n", return 0); 541 - 542 - return 1; 543 598 } 544 599 545 600 /* Warning: The following hash functions assume a power of two 'size'. */
+7 -5
net/sctp/Kconfig
··· 30 30 homing at either or both ends of an association." 31 31 32 32 To compile this protocol support as a module, choose M here: the 33 - module will be called sctp. 33 + module will be called sctp. Debug messages are handeled by the 34 + kernel's dynamic debugging framework. 34 35 35 36 If in doubt, say N. 36 37 ··· 49 48 To compile this code as a module, choose M here: the 50 49 module will be called sctp_probe. 51 50 52 - config SCTP_DBG_MSG 53 - bool "SCTP: Debug messages" 51 + config SCTP_DBG_TSNS 52 + bool "SCTP: Debug transactions" 54 53 help 55 - If you say Y, this will enable verbose debugging messages. 54 + If you say Y, this will enable transaction debugging, visible 55 + from the kernel's dynamic debugging framework. 56 56 57 57 If unsure, say N. However, if you are running into problems, use 58 - this option to gather detailed trace information 58 + this option to gather outqueue trace information. 59 59 60 60 config SCTP_DBG_OBJCNT 61 61 bool "SCTP: Debug object counts"
+33 -34
net/sctp/associola.c
··· 357 357 goto fail_init; 358 358 359 359 SCTP_DBG_OBJCNT_INC(assoc); 360 - SCTP_DEBUG_PRINTK("Created asoc %p\n", asoc); 360 + 361 + pr_debug("Created asoc %p\n", asoc); 361 362 362 363 return asoc; 363 364 ··· 456 455 /* Cleanup and free up an association. */ 457 456 static void sctp_association_destroy(struct sctp_association *asoc) 458 457 { 459 - SCTP_ASSERT(asoc->base.dead, "Assoc is not dead", return); 458 + if (unlikely(!asoc->base.dead)) { 459 + WARN(1, "Attempt to destroy undead association %p!\n", asoc); 460 + return; 461 + } 460 462 461 463 sctp_endpoint_put(asoc->ep); 462 464 sock_put(asoc->base.sk); ··· 540 536 struct list_head *pos; 541 537 struct sctp_transport *transport; 542 538 543 - SCTP_DEBUG_PRINTK_IPADDR("sctp_assoc_rm_peer:association %p addr: ", 544 - " port: %d\n", 545 - asoc, 546 - (&peer->ipaddr), 547 - ntohs(peer->ipaddr.v4.sin_port)); 539 + pr_debug("%s: association:%p addr:%pISpc\n", 540 + __func__, asoc, &peer->ipaddr.sa); 548 541 549 542 /* If we are to remove the current retran_path, update it 550 543 * to the next peer before removing this peer from the list. ··· 637 636 /* AF_INET and AF_INET6 share common port field. */ 638 637 port = ntohs(addr->v4.sin_port); 639 638 640 - SCTP_DEBUG_PRINTK_IPADDR("sctp_assoc_add_peer:association %p addr: ", 641 - " port: %d state:%d\n", 642 - asoc, 643 - addr, 644 - port, 645 - peer_state); 639 + pr_debug("%s: association:%p addr:%pISpc state:%d\n", __func__, 640 + asoc, &addr->sa, peer_state); 646 641 647 642 /* Set the port if it has not been set yet. */ 648 643 if (0 == asoc->peer.port) ··· 705 708 else 706 709 asoc->pathmtu = peer->pathmtu; 707 710 708 - SCTP_DEBUG_PRINTK("sctp_assoc_add_peer:association %p PMTU set to " 709 - "%d\n", asoc, asoc->pathmtu); 711 + pr_debug("%s: association:%p PMTU set to %d\n", __func__, asoc, 712 + asoc->pathmtu); 713 + 710 714 peer->pmtu_pending = 0; 711 715 712 716 asoc->frag_point = sctp_frag_point(asoc, asoc->pathmtu); ··· 1347 1349 else 1348 1350 t = asoc->peer.retran_path; 1349 1351 1350 - SCTP_DEBUG_PRINTK_IPADDR("sctp_assoc_update_retran_path:association" 1351 - " %p addr: ", 1352 - " port: %d\n", 1353 - asoc, 1354 - (&t->ipaddr), 1355 - ntohs(t->ipaddr.v4.sin_port)); 1352 + pr_debug("%s: association:%p addr:%pISpc\n", __func__, asoc, 1353 + &t->ipaddr.sa); 1356 1354 } 1357 1355 1358 1356 /* Choose the transport for sending retransmit packet. */ ··· 1395 1401 asoc->frag_point = sctp_frag_point(asoc, pmtu); 1396 1402 } 1397 1403 1398 - SCTP_DEBUG_PRINTK("%s: asoc:%p, pmtu:%d, frag_point:%d\n", 1399 - __func__, asoc, asoc->pathmtu, asoc->frag_point); 1404 + pr_debug("%s: asoc:%p, pmtu:%d, frag_point:%d\n", __func__, asoc, 1405 + asoc->pathmtu, asoc->frag_point); 1400 1406 } 1401 1407 1402 1408 /* Should we send a SACK to update our peer? */ ··· 1448 1454 asoc->rwnd_press -= change; 1449 1455 } 1450 1456 1451 - SCTP_DEBUG_PRINTK("%s: asoc %p rwnd increased by %d to (%u, %u) " 1452 - "- %u\n", __func__, asoc, len, asoc->rwnd, 1453 - asoc->rwnd_over, asoc->a_rwnd); 1457 + pr_debug("%s: asoc:%p rwnd increased by %d to (%u, %u) - %u\n", 1458 + __func__, asoc, len, asoc->rwnd, asoc->rwnd_over, 1459 + asoc->a_rwnd); 1454 1460 1455 1461 /* Send a window update SACK if the rwnd has increased by at least the 1456 1462 * minimum of the association's PMTU and half of the receive buffer. ··· 1459 1465 */ 1460 1466 if (sctp_peer_needs_update(asoc)) { 1461 1467 asoc->a_rwnd = asoc->rwnd; 1462 - SCTP_DEBUG_PRINTK("%s: Sending window update SACK- asoc: %p " 1463 - "rwnd: %u a_rwnd: %u\n", __func__, 1464 - asoc, asoc->rwnd, asoc->a_rwnd); 1468 + 1469 + pr_debug("%s: sending window update SACK- asoc:%p rwnd:%u " 1470 + "a_rwnd:%u\n", __func__, asoc, asoc->rwnd, 1471 + asoc->a_rwnd); 1472 + 1465 1473 sack = sctp_make_sack(asoc); 1466 1474 if (!sack) 1467 1475 return; ··· 1485 1489 int rx_count; 1486 1490 int over = 0; 1487 1491 1488 - SCTP_ASSERT(asoc->rwnd, "rwnd zero", return); 1489 - SCTP_ASSERT(!asoc->rwnd_over, "rwnd_over not zero", return); 1492 + if (unlikely(!asoc->rwnd || asoc->rwnd_over)) 1493 + pr_debug("%s: association:%p has asoc->rwnd:%u, " 1494 + "asoc->rwnd_over:%u!\n", __func__, asoc, 1495 + asoc->rwnd, asoc->rwnd_over); 1490 1496 1491 1497 if (asoc->ep->rcvbuf_policy) 1492 1498 rx_count = atomic_read(&asoc->rmem_alloc); ··· 1513 1515 asoc->rwnd_over = len - asoc->rwnd; 1514 1516 asoc->rwnd = 0; 1515 1517 } 1516 - SCTP_DEBUG_PRINTK("%s: asoc %p rwnd decreased by %d to (%u, %u, %u)\n", 1517 - __func__, asoc, len, asoc->rwnd, 1518 - asoc->rwnd_over, asoc->rwnd_press); 1518 + 1519 + pr_debug("%s: asoc:%p rwnd decreased by %d to (%u, %u, %u)\n", 1520 + __func__, asoc, len, asoc->rwnd, asoc->rwnd_over, 1521 + asoc->rwnd_press); 1519 1522 } 1520 1523 1521 1524 /* Build the bind address list for the association based on info from the
+3 -2
net/sctp/chunk.c
··· 193 193 msg->expires_at = jiffies + 194 194 msecs_to_jiffies(sinfo->sinfo_timetolive); 195 195 msg->can_abandon = 1; 196 - SCTP_DEBUG_PRINTK("%s: msg:%p expires_at: %ld jiffies:%ld\n", 197 - __func__, msg, msg->expires_at, jiffies); 196 + 197 + pr_debug("%s: msg:%p expires_at:%ld jiffies:%ld\n", __func__, 198 + msg, msg->expires_at, jiffies); 198 199 } 199 200 200 201 /* This is the biggest possible DATA chunk that can fit into
-4
net/sctp/debug.c
··· 47 47 48 48 #include <net/sctp/sctp.h> 49 49 50 - #if SCTP_DEBUG 51 - int sctp_debug_flag = 1; /* Initially enable DEBUG */ 52 - #endif /* SCTP_DEBUG */ 53 - 54 50 /* These are printable forms of Chunk ID's from section 3.1. */ 55 51 static const char *const sctp_cid_tbl[SCTP_NUM_BASE_CHUNK_TYPES] = { 56 52 "DATA",
+4 -1
net/sctp/endpointola.c
··· 249 249 { 250 250 struct sock *sk; 251 251 252 - SCTP_ASSERT(ep->base.dead, "Endpoint is not dead", return); 252 + if (unlikely(!ep->base.dead)) { 253 + WARN(1, "Attempt to destroy undead endpoint %p!\n", ep); 254 + return; 255 + } 253 256 254 257 /* Free the digest buffer */ 255 258 kfree(ep->digest);
+3 -3
net/sctp/input.c
··· 454 454 struct sctp_association *asoc, 455 455 struct sctp_transport *t) 456 456 { 457 - SCTP_DEBUG_PRINTK("%s\n", __func__); 458 - 459 457 if (sock_owned_by_user(sk)) { 460 458 if (timer_pending(&t->proto_unreach_timer)) 461 459 return; ··· 462 464 jiffies + (HZ/20))) 463 465 sctp_association_hold(asoc); 464 466 } 465 - 466 467 } else { 467 468 struct net *net = sock_net(sk); 469 + 470 + pr_debug("%s: unrecognized next header type " 471 + "encountered!\n", __func__); 468 472 469 473 if (del_timer(&t->proto_unreach_timer)) 470 474 sctp_association_put(asoc);
+4 -5
net/sctp/inqueue.c
··· 219 219 chunk->end_of_packet = 1; 220 220 } 221 221 222 - SCTP_DEBUG_PRINTK("+++sctp_inq_pop+++ chunk %p[%s]," 223 - " length %d, skb->len %d\n",chunk, 224 - sctp_cname(SCTP_ST_CHUNK(chunk->chunk_hdr->type)), 225 - ntohs(chunk->chunk_hdr->length), chunk->skb->len); 222 + pr_debug("+++sctp_inq_pop+++ chunk:%p[%s], length:%d, skb->len:%d\n", 223 + chunk, sctp_cname(SCTP_ST_CHUNK(chunk->chunk_hdr->type)), 224 + ntohs(chunk->chunk_hdr->length), chunk->skb->len); 225 + 226 226 return chunk; 227 227 } 228 228 ··· 238 238 { 239 239 INIT_WORK(&q->immediate, callback); 240 240 } 241 -
+12 -9
net/sctp/ipv6.c
··· 239 239 fl6.daddr = *rt0->addr; 240 240 } 241 241 242 - SCTP_DEBUG_PRINTK("%s: skb:%p, len:%d, src:%pI6 dst:%pI6\n", 243 - __func__, skb, skb->len, 244 - &fl6.saddr, &fl6.daddr); 242 + pr_debug("%s: skb:%p, len:%d, src:%pI6 dst:%pI6\n", __func__, skb, 243 + skb->len, &fl6.saddr, &fl6.daddr); 245 244 246 245 SCTP_INC_STATS(sock_net(sk), SCTP_MIB_OUTSCTPPACKS); 247 246 ··· 275 276 if (ipv6_addr_type(&daddr->v6.sin6_addr) & IPV6_ADDR_LINKLOCAL) 276 277 fl6->flowi6_oif = daddr->v6.sin6_scope_id; 277 278 278 - SCTP_DEBUG_PRINTK("%s: DST=%pI6 ", __func__, &fl6->daddr); 279 + pr_debug("%s: dst=%pI6 ", __func__, &fl6->daddr); 279 280 280 281 if (asoc) 281 282 fl6->fl6_sport = htons(asoc->base.bind_addr.port); ··· 283 284 if (saddr) { 284 285 fl6->saddr = saddr->v6.sin6_addr; 285 286 fl6->fl6_sport = saddr->v6.sin6_port; 286 - SCTP_DEBUG_PRINTK("SRC=%pI6 - ", &fl6->saddr); 287 + 288 + pr_debug("src=%pI6 - ", &fl6->saddr); 287 289 } 288 290 289 291 dst = ip6_dst_lookup_flow(sk, fl6, NULL, false); ··· 348 348 out: 349 349 if (!IS_ERR_OR_NULL(dst)) { 350 350 struct rt6_info *rt; 351 + 351 352 rt = (struct rt6_info *)dst; 352 353 t->dst = dst; 353 - SCTP_DEBUG_PRINTK("rt6_dst:%pI6 rt6_src:%pI6\n", 354 - &rt->rt6i_dst.addr, &fl6->saddr); 354 + 355 + pr_debug("rt6_dst:%pI6 rt6_src:%pI6\n", &rt->rt6i_dst.addr, 356 + &fl6->saddr); 355 357 } else { 356 358 t->dst = NULL; 357 - SCTP_DEBUG_PRINTK("NO ROUTE\n"); 359 + 360 + pr_debug("no route\n"); 358 361 } 359 362 } 360 363 ··· 380 377 struct flowi6 *fl6 = &fl->u.ip6; 381 378 union sctp_addr *saddr = &t->saddr; 382 379 383 - SCTP_DEBUG_PRINTK("%s: asoc:%p dst:%p\n", __func__, t->asoc, t->dst); 380 + pr_debug("%s: asoc:%p dst:%p\n", __func__, t->asoc, t->dst); 384 381 385 382 if (t->dst) { 386 383 saddr->v6.sin6_family = AF_INET6;
+17 -23
net/sctp/output.c
··· 93 93 { 94 94 struct sctp_chunk *chunk = NULL; 95 95 96 - SCTP_DEBUG_PRINTK("%s: packet:%p vtag:0x%x\n", __func__, 97 - packet, vtag); 96 + pr_debug("%s: packet:%p vtag:0x%x\n", __func__, packet, vtag); 98 97 99 98 packet->vtag = vtag; 100 99 ··· 118 119 struct sctp_association *asoc = transport->asoc; 119 120 size_t overhead; 120 121 121 - SCTP_DEBUG_PRINTK("%s: packet:%p transport:%p\n", __func__, 122 - packet, transport); 122 + pr_debug("%s: packet:%p transport:%p\n", __func__, packet, transport); 123 123 124 124 packet->transport = transport; 125 125 packet->source_port = sport; ··· 143 145 { 144 146 struct sctp_chunk *chunk, *tmp; 145 147 146 - SCTP_DEBUG_PRINTK("%s: packet:%p\n", __func__, packet); 148 + pr_debug("%s: packet:%p\n", __func__, packet); 147 149 148 150 list_for_each_entry_safe(chunk, tmp, &packet->chunk_list, list) { 149 151 list_del_init(&chunk->list); ··· 165 167 sctp_xmit_t retval; 166 168 int error = 0; 167 169 168 - SCTP_DEBUG_PRINTK("%s: packet:%p chunk:%p\n", __func__, 169 - packet, chunk); 170 + pr_debug("%s: packet:%p chunk:%p\n", __func__, packet, chunk); 170 171 171 172 switch ((retval = (sctp_packet_append_chunk(packet, chunk)))) { 172 173 case SCTP_XMIT_PMTU_FULL: ··· 331 334 { 332 335 sctp_xmit_t retval = SCTP_XMIT_OK; 333 336 334 - SCTP_DEBUG_PRINTK("%s: packet:%p chunk:%p\n", __func__, packet, 335 - chunk); 337 + pr_debug("%s: packet:%p chunk:%p\n", __func__, packet, chunk); 336 338 337 339 /* Data chunks are special. Before seeing what else we can 338 340 * bundle into this packet, check to see if we are allowed to ··· 398 402 unsigned char *auth = NULL; /* pointer to auth in skb data */ 399 403 __u32 cksum_buf_len = sizeof(struct sctphdr); 400 404 401 - SCTP_DEBUG_PRINTK("%s: packet:%p\n", __func__, packet); 405 + pr_debug("%s: packet:%p\n", __func__, packet); 402 406 403 407 /* Do NOT generate a chunkless packet. */ 404 408 if (list_empty(&packet->chunk_list)) ··· 468 472 * 469 473 * [This whole comment explains WORD_ROUND() below.] 470 474 */ 471 - SCTP_DEBUG_PRINTK("***sctp_transmit_packet***\n"); 475 + 476 + pr_debug("***sctp_transmit_packet***\n"); 477 + 472 478 list_for_each_entry_safe(chunk, tmp, &packet->chunk_list, list) { 473 479 list_del_init(&chunk->list); 474 480 if (sctp_chunk_is_data(chunk)) { ··· 503 505 memcpy(skb_put(nskb, chunk->skb->len), 504 506 chunk->skb->data, chunk->skb->len); 505 507 506 - SCTP_DEBUG_PRINTK("%s %p[%s] %s 0x%x, %s %d, %s %d, %s %d\n", 507 - "*** Chunk", chunk, 508 - sctp_cname(SCTP_ST_CHUNK( 509 - chunk->chunk_hdr->type)), 510 - chunk->has_tsn ? "TSN" : "No TSN", 511 - chunk->has_tsn ? 512 - ntohl(chunk->subh.data_hdr->tsn) : 0, 513 - "length", ntohs(chunk->chunk_hdr->length), 514 - "chunk->skb->len", chunk->skb->len, 515 - "rtt_in_progress", chunk->rtt_in_progress); 508 + pr_debug("*** Chunk:%p[%s] %s 0x%x, length:%d, chunk->skb->len:%d, " 509 + "rtt_in_progress:%d\n", chunk, 510 + sctp_cname(SCTP_ST_CHUNK(chunk->chunk_hdr->type)), 511 + chunk->has_tsn ? "TSN" : "No TSN", 512 + chunk->has_tsn ? ntohl(chunk->subh.data_hdr->tsn) : 0, 513 + ntohs(chunk->chunk_hdr->length), chunk->skb->len, 514 + chunk->rtt_in_progress); 516 515 517 516 /* 518 517 * If this is a control chunk, this is our last ··· 601 606 } 602 607 } 603 608 604 - SCTP_DEBUG_PRINTK("***sctp_transmit_packet*** skb len %d\n", 605 - nskb->len); 609 + pr_debug("***sctp_transmit_packet*** skb->len:%d\n", nskb->len); 606 610 607 611 nskb->local_df = packet->ipfragok; 608 612 (*tp->af_specific->sctp_xmit)(nskb, tp);
+70 -90
net/sctp/outqueue.c
··· 299 299 struct net *net = sock_net(q->asoc->base.sk); 300 300 int error = 0; 301 301 302 - SCTP_DEBUG_PRINTK("sctp_outq_tail(%p, %p[%s])\n", 303 - q, chunk, chunk && chunk->chunk_hdr ? 304 - sctp_cname(SCTP_ST_CHUNK(chunk->chunk_hdr->type)) 305 - : "Illegal Chunk"); 302 + pr_debug("%s: outq:%p, chunk:%p[%s]\n", __func__, q, chunk, 303 + chunk && chunk->chunk_hdr ? 304 + sctp_cname(SCTP_ST_CHUNK(chunk->chunk_hdr->type)) : 305 + "illegal chunk"); 306 306 307 307 /* If it is data, queue it up, otherwise, send it 308 308 * immediately. ··· 328 328 break; 329 329 330 330 default: 331 - SCTP_DEBUG_PRINTK("outqueueing (%p, %p[%s])\n", 332 - q, chunk, chunk && chunk->chunk_hdr ? 333 - sctp_cname(SCTP_ST_CHUNK(chunk->chunk_hdr->type)) 334 - : "Illegal Chunk"); 331 + pr_debug("%s: outqueueing: outq:%p, chunk:%p[%s])\n", 332 + __func__, q, chunk, chunk && chunk->chunk_hdr ? 333 + sctp_cname(SCTP_ST_CHUNK(chunk->chunk_hdr->type)) : 334 + "illegal chunk"); 335 335 336 336 sctp_outq_tail_data(q, chunk); 337 337 if (chunk->chunk_hdr->flags & SCTP_DATA_UNORDERED) ··· 460 460 } 461 461 } 462 462 463 - SCTP_DEBUG_PRINTK("%s: transport: %p, reason: %d, " 464 - "cwnd: %d, ssthresh: %d, flight_size: %d, " 465 - "pba: %d\n", __func__, 466 - transport, reason, 467 - transport->cwnd, transport->ssthresh, 468 - transport->flight_size, 469 - transport->partial_bytes_acked); 470 - 463 + pr_debug("%s: transport:%p, reason:%d, cwnd:%d, ssthresh:%d, " 464 + "flight_size:%d, pba:%d\n", __func__, transport, reason, 465 + transport->cwnd, transport->ssthresh, transport->flight_size, 466 + transport->partial_bytes_acked); 471 467 } 472 468 473 469 /* Mark all the eligible packets on a transport for retransmission and force ··· 1010 1014 sctp_transport_burst_limited(transport); 1011 1015 } 1012 1016 1013 - SCTP_DEBUG_PRINTK("sctp_outq_flush(%p, %p[%s]), ", 1014 - q, chunk, 1015 - chunk && chunk->chunk_hdr ? 1016 - sctp_cname(SCTP_ST_CHUNK( 1017 - chunk->chunk_hdr->type)) 1018 - : "Illegal Chunk"); 1019 - 1020 - SCTP_DEBUG_PRINTK("TX TSN 0x%x skb->head " 1021 - "%p skb->users %d.\n", 1022 - ntohl(chunk->subh.data_hdr->tsn), 1023 - chunk->skb ?chunk->skb->head : NULL, 1024 - chunk->skb ? 1025 - atomic_read(&chunk->skb->users) : -1); 1017 + pr_debug("%s: outq:%p, chunk:%p[%s], tx-tsn:0x%x skb->head:%p " 1018 + "skb->users:%d\n", 1019 + __func__, q, chunk, chunk && chunk->chunk_hdr ? 1020 + sctp_cname(SCTP_ST_CHUNK(chunk->chunk_hdr->type)) : 1021 + "illegal chunk", ntohl(chunk->subh.data_hdr->tsn), 1022 + chunk->skb ? chunk->skb->head : NULL, chunk->skb ? 1023 + atomic_read(&chunk->skb->users) : -1); 1026 1024 1027 1025 /* Add the chunk to the packet. */ 1028 1026 status = sctp_packet_transmit_chunk(packet, chunk, 0); ··· 1028 1038 /* We could not append this chunk, so put 1029 1039 * the chunk back on the output queue. 1030 1040 */ 1031 - SCTP_DEBUG_PRINTK("sctp_outq_flush: could " 1032 - "not transmit TSN: 0x%x, status: %d\n", 1033 - ntohl(chunk->subh.data_hdr->tsn), 1034 - status); 1041 + pr_debug("%s: could not transmit tsn:0x%x, status:%d\n", 1042 + __func__, ntohl(chunk->subh.data_hdr->tsn), 1043 + status); 1044 + 1035 1045 sctp_outq_head_data(q, chunk); 1036 1046 goto sctp_flush_out; 1037 1047 break; ··· 1274 1284 1275 1285 sctp_generate_fwdtsn(q, sack_ctsn); 1276 1286 1277 - SCTP_DEBUG_PRINTK("%s: sack Cumulative TSN Ack is 0x%x.\n", 1278 - __func__, sack_ctsn); 1279 - SCTP_DEBUG_PRINTK("%s: Cumulative TSN Ack of association, " 1280 - "%p is 0x%x. Adv peer ack point: 0x%x\n", 1281 - __func__, asoc, ctsn, asoc->adv_peer_ack_point); 1287 + pr_debug("%s: sack cumulative tsn ack:0x%x\n", __func__, sack_ctsn); 1288 + pr_debug("%s: cumulative tsn ack of assoc:%p is 0x%x, " 1289 + "advertised peer ack point:0x%x\n", __func__, asoc, ctsn, 1290 + asoc->adv_peer_ack_point); 1282 1291 1283 1292 /* See if all chunks are acked. 1284 1293 * Make sure the empty queue handler will get run later. ··· 1293 1304 goto finish; 1294 1305 } 1295 1306 1296 - SCTP_DEBUG_PRINTK("sack queue is empty.\n"); 1307 + pr_debug("%s: sack queue is empty\n", __func__); 1297 1308 finish: 1298 1309 return q->empty; 1299 1310 } ··· 1337 1348 1338 1349 /* These state variables are for coherent debug output. --xguo */ 1339 1350 1340 - #if SCTP_DEBUG 1351 + #ifdef CONFIG_SCTP_DBG_TSNS 1341 1352 __u32 dbg_ack_tsn = 0; /* An ACKed TSN range starts here... */ 1342 1353 __u32 dbg_last_ack_tsn = 0; /* ...and finishes here. */ 1343 1354 __u32 dbg_kept_tsn = 0; /* An un-ACKed range starts here... */ ··· 1348 1359 * -1: We need to initialize. 1349 1360 */ 1350 1361 int dbg_prt_state = -1; 1351 - #endif /* SCTP_DEBUG */ 1362 + #endif /* CONFIG_SCTP_DBG_TSNS */ 1352 1363 1353 1364 sack_ctsn = ntohl(sack->cum_tsn_ack); 1354 1365 ··· 1472 1483 list_add_tail(lchunk, &tlist); 1473 1484 } 1474 1485 1475 - #if SCTP_DEBUG 1486 + #ifdef CONFIG_SCTP_DBG_TSNS 1476 1487 switch (dbg_prt_state) { 1477 1488 case 0: /* last TSN was ACKed */ 1478 1489 if (dbg_last_ack_tsn + 1 == tsn) { ··· 1486 1497 /* Display the end of the 1487 1498 * current range. 1488 1499 */ 1489 - SCTP_DEBUG_PRINTK_CONT("-%08x", 1490 - dbg_last_ack_tsn); 1500 + pr_cont("-%08x", dbg_last_ack_tsn); 1491 1501 } 1492 1502 1493 1503 /* Start a new range. */ 1494 - SCTP_DEBUG_PRINTK_CONT(",%08x", tsn); 1504 + pr_cont(",%08x", tsn); 1495 1505 dbg_ack_tsn = tsn; 1496 1506 break; 1497 1507 1498 1508 case 1: /* The last TSN was NOT ACKed. */ 1499 1509 if (dbg_last_kept_tsn != dbg_kept_tsn) { 1500 1510 /* Display the end of current range. */ 1501 - SCTP_DEBUG_PRINTK_CONT("-%08x", 1502 - dbg_last_kept_tsn); 1511 + pr_cont("-%08x", dbg_last_kept_tsn); 1503 1512 } 1504 1513 1505 - SCTP_DEBUG_PRINTK_CONT("\n"); 1506 - 1514 + pr_cont("\n"); 1507 1515 /* FALL THROUGH... */ 1508 1516 default: 1509 1517 /* This is the first-ever TSN we examined. */ 1510 1518 /* Start a new range of ACK-ed TSNs. */ 1511 - SCTP_DEBUG_PRINTK("ACKed: %08x", tsn); 1519 + pr_debug("ACKed: %08x", tsn); 1520 + 1512 1521 dbg_prt_state = 0; 1513 1522 dbg_ack_tsn = tsn; 1514 1523 } 1515 1524 1516 1525 dbg_last_ack_tsn = tsn; 1517 - #endif /* SCTP_DEBUG */ 1526 + #endif /* CONFIG_SCTP_DBG_TSNS */ 1518 1527 1519 1528 } else { 1520 1529 if (tchunk->tsn_gap_acked) { 1521 - SCTP_DEBUG_PRINTK("%s: Receiver reneged on " 1522 - "data TSN: 0x%x\n", 1523 - __func__, 1524 - tsn); 1530 + pr_debug("%s: receiver reneged on data TSN:0x%x\n", 1531 + __func__, tsn); 1532 + 1525 1533 tchunk->tsn_gap_acked = 0; 1526 1534 1527 1535 if (tchunk->transport) ··· 1538 1552 1539 1553 list_add_tail(lchunk, &tlist); 1540 1554 1541 - #if SCTP_DEBUG 1555 + #ifdef CONFIG_SCTP_DBG_TSNS 1542 1556 /* See the above comments on ACK-ed TSNs. */ 1543 1557 switch (dbg_prt_state) { 1544 1558 case 1: ··· 1546 1560 break; 1547 1561 1548 1562 if (dbg_last_kept_tsn != dbg_kept_tsn) 1549 - SCTP_DEBUG_PRINTK_CONT("-%08x", 1550 - dbg_last_kept_tsn); 1563 + pr_cont("-%08x", dbg_last_kept_tsn); 1551 1564 1552 - SCTP_DEBUG_PRINTK_CONT(",%08x", tsn); 1565 + pr_cont(",%08x", tsn); 1553 1566 dbg_kept_tsn = tsn; 1554 1567 break; 1555 1568 1556 1569 case 0: 1557 1570 if (dbg_last_ack_tsn != dbg_ack_tsn) 1558 - SCTP_DEBUG_PRINTK_CONT("-%08x", 1559 - dbg_last_ack_tsn); 1560 - SCTP_DEBUG_PRINTK_CONT("\n"); 1571 + pr_cont("-%08x", dbg_last_ack_tsn); 1561 1572 1573 + pr_cont("\n"); 1562 1574 /* FALL THROUGH... */ 1563 1575 default: 1564 - SCTP_DEBUG_PRINTK("KEPT: %08x",tsn); 1576 + pr_debug("KEPT: %08x", tsn); 1577 + 1565 1578 dbg_prt_state = 1; 1566 1579 dbg_kept_tsn = tsn; 1567 1580 } 1568 1581 1569 1582 dbg_last_kept_tsn = tsn; 1570 - #endif /* SCTP_DEBUG */ 1583 + #endif /* CONFIG_SCTP_DBG_TSNS */ 1571 1584 } 1572 1585 } 1573 1586 1574 - #if SCTP_DEBUG 1587 + #ifdef CONFIG_SCTP_DBG_TSNS 1575 1588 /* Finish off the last range, displaying its ending TSN. */ 1576 1589 switch (dbg_prt_state) { 1577 1590 case 0: 1578 - if (dbg_last_ack_tsn != dbg_ack_tsn) { 1579 - SCTP_DEBUG_PRINTK_CONT("-%08x\n", dbg_last_ack_tsn); 1580 - } else { 1581 - SCTP_DEBUG_PRINTK_CONT("\n"); 1582 - } 1583 - break; 1584 - 1591 + if (dbg_last_ack_tsn != dbg_ack_tsn) 1592 + pr_cont("-%08x\n", dbg_last_ack_tsn); 1593 + else 1594 + pr_cont("\n"); 1595 + break; 1585 1596 case 1: 1586 - if (dbg_last_kept_tsn != dbg_kept_tsn) { 1587 - SCTP_DEBUG_PRINTK_CONT("-%08x\n", dbg_last_kept_tsn); 1588 - } else { 1589 - SCTP_DEBUG_PRINTK_CONT("\n"); 1590 - } 1597 + if (dbg_last_kept_tsn != dbg_kept_tsn) 1598 + pr_cont("-%08x\n", dbg_last_kept_tsn); 1599 + else 1600 + pr_cont("\n"); 1601 + break; 1591 1602 } 1592 - #endif /* SCTP_DEBUG */ 1603 + #endif /* CONFIG_SCTP_DBG_TSNS */ 1593 1604 if (transport) { 1594 1605 if (bytes_acked) { 1595 1606 struct sctp_association *asoc = transport->asoc; ··· 1659 1676 !list_empty(&tlist) && 1660 1677 (sack_ctsn+2 == q->asoc->next_tsn) && 1661 1678 q->asoc->state < SCTP_STATE_SHUTDOWN_PENDING) { 1662 - SCTP_DEBUG_PRINTK("%s: SACK received for zero " 1663 - "window probe: %u\n", 1664 - __func__, sack_ctsn); 1679 + pr_debug("%s: sack received for zero window " 1680 + "probe:%u\n", __func__, sack_ctsn); 1681 + 1665 1682 q->asoc->overall_error_count = 0; 1666 1683 transport->error_count = 0; 1667 1684 } ··· 1722 1739 count_of_newacks, tsn)) { 1723 1740 chunk->tsn_missing_report++; 1724 1741 1725 - SCTP_DEBUG_PRINTK( 1726 - "%s: TSN 0x%x missing counter: %d\n", 1727 - __func__, tsn, 1728 - chunk->tsn_missing_report); 1742 + pr_debug("%s: tsn:0x%x missing counter:%d\n", 1743 + __func__, tsn, chunk->tsn_missing_report); 1729 1744 } 1730 1745 } 1731 1746 /* ··· 1743 1762 if (do_fast_retransmit) 1744 1763 sctp_retransmit(q, transport, SCTP_RTXR_FAST_RTX); 1745 1764 1746 - SCTP_DEBUG_PRINTK("%s: transport: %p, cwnd: %d, " 1747 - "ssthresh: %d, flight_size: %d, pba: %d\n", 1748 - __func__, transport, transport->cwnd, 1749 - transport->ssthresh, transport->flight_size, 1750 - transport->partial_bytes_acked); 1765 + pr_debug("%s: transport:%p, cwnd:%d, ssthresh:%d, " 1766 + "flight_size:%d, pba:%d\n", __func__, transport, 1767 + transport->cwnd, transport->ssthresh, 1768 + transport->flight_size, transport->partial_bytes_acked); 1751 1769 } 1752 1770 } 1753 1771
+25 -23
net/sctp/protocol.c
··· 451 451 fl4->fl4_sport = saddr->v4.sin_port; 452 452 } 453 453 454 - SCTP_DEBUG_PRINTK("%s: DST:%pI4, SRC:%pI4 - ", 455 - __func__, &fl4->daddr, &fl4->saddr); 454 + pr_debug("%s: dst:%pI4, src:%pI4 - ", __func__, &fl4->daddr, 455 + &fl4->saddr); 456 456 457 457 rt = ip_route_output_key(sock_net(sk), fl4); 458 458 if (!IS_ERR(rt)) ··· 513 513 out: 514 514 t->dst = dst; 515 515 if (dst) 516 - SCTP_DEBUG_PRINTK("rt_dst:%pI4, rt_src:%pI4\n", 517 - &fl4->daddr, &fl4->saddr); 516 + pr_debug("rt_dst:%pI4, rt_src:%pI4\n", 517 + &fl4->daddr, &fl4->saddr); 518 518 else 519 - SCTP_DEBUG_PRINTK("NO ROUTE\n"); 519 + pr_debug("no route\n"); 520 520 } 521 521 522 522 /* For v4, the source address is cached in the route entry(dst). So no need ··· 604 604 spin_lock_bh(&net->sctp.addr_wq_lock); 605 605 606 606 list_for_each_entry_safe(addrw, temp, &net->sctp.addr_waitq, list) { 607 - SCTP_DEBUG_PRINTK_IPADDR("sctp_addrwq_timo_handler: the first ent in wq %p is ", 608 - " for cmd %d at entry %p\n", &net->sctp.addr_waitq, &addrw->a, addrw->state, 609 - addrw); 607 + pr_debug("%s: the first ent in wq:%p is addr:%pISc for cmd:%d at " 608 + "entry:%p\n", __func__, &net->sctp.addr_waitq, &addrw->a.sa, 609 + addrw->state, addrw); 610 610 611 611 #if IS_ENABLED(CONFIG_IPV6) 612 612 /* Now we send an ASCONF for each association */ ··· 623 623 addrw->state == SCTP_ADDR_NEW) { 624 624 unsigned long timeo_val; 625 625 626 - SCTP_DEBUG_PRINTK("sctp_timo_handler: this is on DAD, trying %d sec later\n", 627 - SCTP_ADDRESS_TICK_DELAY); 626 + pr_debug("%s: this is on DAD, trying %d sec " 627 + "later\n", __func__, 628 + SCTP_ADDRESS_TICK_DELAY); 629 + 628 630 timeo_val = jiffies; 629 631 timeo_val += msecs_to_jiffies(SCTP_ADDRESS_TICK_DELAY); 630 632 mod_timer(&net->sctp.addr_wq_timer, timeo_val); ··· 643 641 continue; 644 642 sctp_bh_lock_sock(sk); 645 643 if (sctp_asconf_mgmt(sp, addrw) < 0) 646 - SCTP_DEBUG_PRINTK("sctp_addrwq_timo_handler: sctp_asconf_mgmt failed\n"); 644 + pr_debug("%s: sctp_asconf_mgmt failed\n", __func__); 647 645 sctp_bh_unlock_sock(sk); 648 646 } 649 647 #if IS_ENABLED(CONFIG_IPV6) ··· 709 707 addrw = sctp_addr_wq_lookup(net, addr); 710 708 if (addrw) { 711 709 if (addrw->state != cmd) { 712 - SCTP_DEBUG_PRINTK_IPADDR("sctp_addr_wq_mgmt offsets existing entry for %d ", 713 - " in wq %p\n", addrw->state, &addrw->a, 714 - &net->sctp.addr_waitq); 710 + pr_debug("%s: offsets existing entry for %d, addr:%pISc " 711 + "in wq:%p\n", __func__, addrw->state, &addrw->a.sa, 712 + &net->sctp.addr_waitq); 713 + 715 714 list_del(&addrw->list); 716 715 kfree(addrw); 717 716 } ··· 728 725 } 729 726 addrw->state = cmd; 730 727 list_add_tail(&addrw->list, &net->sctp.addr_waitq); 731 - SCTP_DEBUG_PRINTK_IPADDR("sctp_addr_wq_mgmt add new entry for cmd:%d ", 732 - " in wq %p\n", addrw->state, &addrw->a, &net->sctp.addr_waitq); 728 + 729 + pr_debug("%s: add new entry for cmd:%d, addr:%pISc in wq:%p\n", 730 + __func__, addrw->state, &addrw->a.sa, &net->sctp.addr_waitq); 733 731 734 732 if (!timer_pending(&net->sctp.addr_wq_timer)) { 735 733 timeo_val = jiffies; ··· 956 952 { 957 953 struct inet_sock *inet = inet_sk(skb->sk); 958 954 959 - SCTP_DEBUG_PRINTK("%s: skb:%p, len:%d, src:%pI4, dst:%pI4\n", 960 - __func__, skb, skb->len, 961 - &transport->fl.u.ip4.saddr, 962 - &transport->fl.u.ip4.daddr); 955 + pr_debug("%s: skb:%p, len:%d, src:%pI4, dst:%pI4\n", __func__, skb, 956 + skb->len, &transport->fl.u.ip4.saddr, &transport->fl.u.ip4.daddr); 963 957 964 958 inet->pmtudisc = transport->param_flags & SPP_PMTUD_ENABLE ? 965 959 IP_PMTUDISC_DO : IP_PMTUDISC_DONT; 966 960 967 961 SCTP_INC_STATS(sock_net(&inet->sk), SCTP_MIB_OUTSCTPPACKS); 962 + 968 963 return ip_queue_xmit(skb, &transport->fl); 969 964 } 970 965 ··· 1324 1321 int max_share; 1325 1322 int order; 1326 1323 1327 - /* SCTP_DEBUG sanity check. */ 1328 - if (!sctp_sanity_check()) 1329 - goto out; 1324 + BUILD_BUG_ON(sizeof(struct sctp_ulpevent) > 1325 + sizeof(((struct sk_buff *) 0)->cb)); 1330 1326 1331 1327 /* Allocate bind_bucket and chunk caches. */ 1332 1328 status = -ENOBUFS;
+14 -11
net/sctp/sm_make_chunk.c
··· 741 741 742 742 memset(gabs, 0, sizeof(gabs)); 743 743 ctsn = sctp_tsnmap_get_ctsn(map); 744 - SCTP_DEBUG_PRINTK("sackCTSNAck sent: 0x%x.\n", ctsn); 744 + 745 + pr_debug("%s: sackCTSNAck sent:0x%x\n", __func__, ctsn); 745 746 746 747 /* How much room is needed in the chunk? */ 747 748 num_gabs = sctp_tsnmap_num_gabs(map, gabs); ··· 1288 1287 1289 1288 if (!retval) 1290 1289 goto nodata; 1291 - 1292 - if (!sk) { 1293 - SCTP_DEBUG_PRINTK("chunkifying skb %p w/o an sk\n", skb); 1294 - } 1290 + if (!sk) 1291 + pr_debug("%s: chunkifying skb:%p w/o an sk\n", __func__, skb); 1295 1292 1296 1293 INIT_LIST_HEAD(&retval->list); 1297 1294 retval->skb = skb; ··· 2190 2191 break; 2191 2192 fallthrough: 2192 2193 default: 2193 - SCTP_DEBUG_PRINTK("Unrecognized param: %d for chunk %d.\n", 2194 - ntohs(param.p->type), cid); 2194 + pr_debug("%s: unrecognized param:%d for chunk:%d\n", 2195 + __func__, ntohs(param.p->type), cid); 2196 + 2195 2197 retval = sctp_process_unk_param(asoc, param, chunk, err_chunk); 2196 2198 break; 2197 2199 } ··· 2516 2516 break; 2517 2517 2518 2518 case SCTP_PARAM_HOST_NAME_ADDRESS: 2519 - SCTP_DEBUG_PRINTK("unimplemented SCTP_HOST_NAME_ADDRESS\n"); 2519 + pr_debug("%s: unimplemented SCTP_HOST_NAME_ADDRESS\n", __func__); 2520 2520 break; 2521 2521 2522 2522 case SCTP_PARAM_SUPPORTED_ADDRESS_TYPES: ··· 2662 2662 * called prior to this routine. Simply log the error 2663 2663 * here. 2664 2664 */ 2665 - SCTP_DEBUG_PRINTK("Ignoring param: %d for association %p.\n", 2666 - ntohs(param.p->type), asoc); 2665 + pr_debug("%s: ignoring param:%d for association:%p.\n", 2666 + __func__, ntohs(param.p->type), asoc); 2667 2667 break; 2668 2668 } 2669 2669 ··· 2805 2805 totallen += paramlen; 2806 2806 totallen += addr_param_len; 2807 2807 del_pickup = 1; 2808 - SCTP_DEBUG_PRINTK("mkasconf_update_ip: picked same-scope del_pending addr, totallen for all addresses is %d\n", totallen); 2808 + 2809 + pr_debug("%s: picked same-scope del_pending addr, " 2810 + "totallen for all addresses is %d\n", 2811 + __func__, totallen); 2809 2812 } 2810 2813 } 2811 2814
+38 -54
net/sctp/sm_sideeffect.c
··· 257 257 258 258 sctp_bh_lock_sock(asoc->base.sk); 259 259 if (sock_owned_by_user(asoc->base.sk)) { 260 - SCTP_DEBUG_PRINTK("%s:Sock is busy.\n", __func__); 260 + pr_debug("%s: sock is busy\n", __func__); 261 261 262 262 /* Try again later. */ 263 263 if (!mod_timer(&transport->T3_rtx_timer, jiffies + (HZ/20))) ··· 297 297 298 298 sctp_bh_lock_sock(asoc->base.sk); 299 299 if (sock_owned_by_user(asoc->base.sk)) { 300 - SCTP_DEBUG_PRINTK("%s:Sock is busy: timer %d\n", 301 - __func__, 302 - timeout_type); 300 + pr_debug("%s: sock is busy: timer %d\n", __func__, 301 + timeout_type); 303 302 304 303 /* Try again later. */ 305 304 if (!mod_timer(&asoc->timers[timeout_type], jiffies + (HZ/20))) ··· 376 377 377 378 sctp_bh_lock_sock(asoc->base.sk); 378 379 if (sock_owned_by_user(asoc->base.sk)) { 379 - SCTP_DEBUG_PRINTK("%s:Sock is busy.\n", __func__); 380 + pr_debug("%s: sock is busy\n", __func__); 380 381 381 382 /* Try again later. */ 382 383 if (!mod_timer(&transport->hb_timer, jiffies + (HZ/20))) ··· 414 415 415 416 sctp_bh_lock_sock(asoc->base.sk); 416 417 if (sock_owned_by_user(asoc->base.sk)) { 417 - SCTP_DEBUG_PRINTK("%s:Sock is busy.\n", __func__); 418 + pr_debug("%s: sock is busy\n", __func__); 418 419 419 420 /* Try again later. */ 420 421 if (!mod_timer(&transport->proto_unreach_timer, ··· 520 521 521 522 if (transport->state != SCTP_INACTIVE && 522 523 (transport->error_count > transport->pathmaxrxt)) { 523 - SCTP_DEBUG_PRINTK_IPADDR("transport_strike:association %p", 524 - " transport IP: port:%d failed.\n", 525 - asoc, 526 - (&transport->ipaddr), 527 - ntohs(transport->ipaddr.v4.sin_port)); 524 + pr_debug("%s: association:%p transport addr:%pISpc failed\n", 525 + __func__, asoc, &transport->ipaddr.sa); 526 + 528 527 sctp_assoc_control_transport(asoc, transport, 529 528 SCTP_TRANSPORT_DOWN, 530 529 SCTP_FAILED_THRESHOLD); ··· 801 804 802 805 asoc->state = state; 803 806 804 - SCTP_DEBUG_PRINTK("sctp_cmd_new_state: asoc %p[%s]\n", 805 - asoc, sctp_state_tbl[state]); 807 + pr_debug("%s: asoc:%p[%s]\n", __func__, asoc, sctp_state_tbl[state]); 806 808 807 809 if (sctp_style(sk, TCP)) { 808 810 /* Change the sk->sk_state of a TCP-style socket that has ··· 1013 1017 asoc->timeouts[timer] = asoc->max_init_timeo; 1014 1018 } 1015 1019 asoc->init_cycle++; 1016 - SCTP_DEBUG_PRINTK( 1017 - "T1 %s Timeout adjustment" 1018 - " init_err_counter: %d" 1019 - " cycle: %d" 1020 - " timeout: %ld\n", 1021 - name, 1022 - asoc->init_err_counter, 1023 - asoc->init_cycle, 1024 - asoc->timeouts[timer]); 1020 + 1021 + pr_debug("%s: T1[%s] timeout adjustment init_err_counter:%d" 1022 + " cycle:%d timeout:%ld\n", __func__, name, 1023 + asoc->init_err_counter, asoc->init_cycle, 1024 + asoc->timeouts[timer]); 1025 1025 } 1026 1026 1027 1027 } ··· 1072 1080 * main flow of sctp_do_sm() to keep attention focused on the real 1073 1081 * functionality there. 1074 1082 */ 1075 - #define DEBUG_PRE \ 1076 - SCTP_DEBUG_PRINTK("sctp_do_sm prefn: " \ 1077 - "ep %p, %s, %s, asoc %p[%s], %s\n", \ 1078 - ep, sctp_evttype_tbl[event_type], \ 1079 - (*debug_fn)(subtype), asoc, \ 1080 - sctp_state_tbl[state], state_fn->name) 1083 + #define debug_pre_sfn() \ 1084 + pr_debug("%s[pre-fn]: ep:%p, %s, %s, asoc:%p[%s], %s\n", __func__, \ 1085 + ep, sctp_evttype_tbl[event_type], (*debug_fn)(subtype), \ 1086 + asoc, sctp_state_tbl[state], state_fn->name) 1081 1087 1082 - #define DEBUG_POST \ 1083 - SCTP_DEBUG_PRINTK("sctp_do_sm postfn: " \ 1084 - "asoc %p, status: %s\n", \ 1085 - asoc, sctp_status_tbl[status]) 1088 + #define debug_post_sfn() \ 1089 + pr_debug("%s[post-fn]: asoc:%p, status:%s\n", __func__, asoc, \ 1090 + sctp_status_tbl[status]) 1086 1091 1087 - #define DEBUG_POST_SFX \ 1088 - SCTP_DEBUG_PRINTK("sctp_do_sm post sfx: error %d, asoc %p[%s]\n", \ 1089 - error, asoc, \ 1090 - sctp_state_tbl[(asoc && sctp_id2assoc(ep->base.sk, \ 1091 - sctp_assoc2id(asoc)))?asoc->state:SCTP_STATE_CLOSED]) 1092 + #define debug_post_sfx() \ 1093 + pr_debug("%s[post-sfx]: error:%d, asoc:%p[%s]\n", __func__, error, \ 1094 + asoc, sctp_state_tbl[(asoc && sctp_id2assoc(ep->base.sk, \ 1095 + sctp_assoc2id(asoc))) ? asoc->state : SCTP_STATE_CLOSED]) 1092 1096 1093 1097 /* 1094 1098 * This is the master state machine processing function. ··· 1104 1116 sctp_disposition_t status; 1105 1117 int error = 0; 1106 1118 typedef const char *(printfn_t)(sctp_subtype_t); 1107 - 1108 1119 static printfn_t *table[] = { 1109 1120 NULL, sctp_cname, sctp_tname, sctp_oname, sctp_pname, 1110 1121 }; ··· 1116 1129 1117 1130 sctp_init_cmd_seq(&commands); 1118 1131 1119 - DEBUG_PRE; 1132 + debug_pre_sfn(); 1120 1133 status = (*state_fn->fn)(net, ep, asoc, subtype, event_arg, &commands); 1121 - DEBUG_POST; 1134 + debug_post_sfn(); 1122 1135 1123 1136 error = sctp_side_effects(event_type, subtype, state, 1124 1137 ep, asoc, event_arg, status, 1125 1138 &commands, gfp); 1126 - DEBUG_POST_SFX; 1139 + debug_post_sfx(); 1127 1140 1128 1141 return error; 1129 1142 } 1130 - 1131 - #undef DEBUG_PRE 1132 - #undef DEBUG_POST 1133 1143 1134 1144 /***************************************************************** 1135 1145 * This the master state function side effect processing function. ··· 1156 1172 1157 1173 switch (status) { 1158 1174 case SCTP_DISPOSITION_DISCARD: 1159 - SCTP_DEBUG_PRINTK("Ignored sctp protocol event - state %d, " 1160 - "event_type %d, event_id %d\n", 1161 - state, event_type, subtype.chunk); 1175 + pr_debug("%s: ignored sctp protocol event - state:%d, " 1176 + "event_type:%d, event_id:%d\n", __func__, state, 1177 + event_type, subtype.chunk); 1162 1178 break; 1163 1179 1164 1180 case SCTP_DISPOSITION_NOMEM: ··· 1409 1425 1410 1426 case SCTP_CMD_CHUNK_ULP: 1411 1427 /* Send a chunk to the sockets layer. */ 1412 - SCTP_DEBUG_PRINTK("sm_sideff: %s %p, %s %p.\n", 1413 - "chunk_up:", cmd->obj.chunk, 1414 - "ulpq:", &asoc->ulpq); 1428 + pr_debug("%s: sm_sideff: chunk_up:%p, ulpq:%p\n", 1429 + __func__, cmd->obj.chunk, &asoc->ulpq); 1430 + 1415 1431 sctp_ulpq_tail_data(&asoc->ulpq, cmd->obj.chunk, 1416 1432 GFP_ATOMIC); 1417 1433 break; 1418 1434 1419 1435 case SCTP_CMD_EVENT_ULP: 1420 1436 /* Send a notification to the sockets layer. */ 1421 - SCTP_DEBUG_PRINTK("sm_sideff: %s %p, %s %p.\n", 1422 - "event_up:",cmd->obj.ulpevent, 1423 - "ulpq:",&asoc->ulpq); 1437 + pr_debug("%s: sm_sideff: event_up:%p, ulpq:%p\n", 1438 + __func__, cmd->obj.ulpevent, &asoc->ulpq); 1439 + 1424 1440 sctp_ulpq_tail_event(&asoc->ulpq, cmd->obj.ulpevent); 1425 1441 break; 1426 1442 ··· 1585 1601 break; 1586 1602 1587 1603 case SCTP_CMD_REPORT_BAD_TAG: 1588 - SCTP_DEBUG_PRINTK("vtag mismatch!\n"); 1604 + pr_debug("%s: vtag mismatch!\n", __func__); 1589 1605 break; 1590 1606 1591 1607 case SCTP_CMD_STRIKE:
+47 -30
net/sctp/sm_statefuns.c
··· 1179 1179 /* Check if the timestamp looks valid. */ 1180 1180 if (time_after(hbinfo->sent_at, jiffies) || 1181 1181 time_after(jiffies, hbinfo->sent_at + max_interval)) { 1182 - SCTP_DEBUG_PRINTK("%s: HEARTBEAT ACK with invalid timestamp " 1183 - "received for transport: %p\n", 1184 - __func__, link); 1182 + pr_debug("%s: HEARTBEAT ACK with invalid timestamp received " 1183 + "for transport:%p\n", __func__, link); 1184 + 1185 1185 return SCTP_DISPOSITION_DISCARD; 1186 1186 } 1187 1187 ··· 2562 2562 const struct sctp_association *asoc, 2563 2563 struct sctp_transport *transport) 2564 2564 { 2565 - SCTP_DEBUG_PRINTK("ABORT received (INIT).\n"); 2565 + pr_debug("%s: ABORT received (INIT)\n", __func__); 2566 + 2566 2567 sctp_add_cmd_sf(commands, SCTP_CMD_NEW_STATE, 2567 2568 SCTP_STATE(SCTP_STATE_CLOSED)); 2568 2569 SCTP_INC_STATS(net, SCTP_MIB_ABORTEDS); ··· 2573 2572 /* CMD_INIT_FAILED will DELETE_TCB. */ 2574 2573 sctp_add_cmd_sf(commands, SCTP_CMD_INIT_FAILED, 2575 2574 SCTP_PERR(error)); 2575 + 2576 2576 return SCTP_DISPOSITION_ABORT; 2577 2577 } 2578 2578 ··· 2639 2637 ctsn = ntohl(sdh->cum_tsn_ack); 2640 2638 2641 2639 if (TSN_lt(ctsn, asoc->ctsn_ack_point)) { 2642 - SCTP_DEBUG_PRINTK("ctsn %x\n", ctsn); 2643 - SCTP_DEBUG_PRINTK("ctsn_ack_point %x\n", asoc->ctsn_ack_point); 2640 + pr_debug("%s: ctsn:%x, ctsn_ack_point:%x\n", __func__, ctsn, 2641 + asoc->ctsn_ack_point); 2642 + 2644 2643 return SCTP_DISPOSITION_DISCARD; 2645 2644 } 2646 2645 ··· 2724 2721 ctsn = ntohl(sdh->cum_tsn_ack); 2725 2722 2726 2723 if (TSN_lt(ctsn, asoc->ctsn_ack_point)) { 2727 - SCTP_DEBUG_PRINTK("ctsn %x\n", ctsn); 2728 - SCTP_DEBUG_PRINTK("ctsn_ack_point %x\n", asoc->ctsn_ack_point); 2724 + pr_debug("%s: ctsn:%x, ctsn_ack_point:%x\n", __func__, ctsn, 2725 + asoc->ctsn_ack_point); 2726 + 2729 2727 return SCTP_DISPOSITION_DISCARD; 2730 2728 } 2731 2729 ··· 3178 3174 * Point indicates an out-of-order SACK. 3179 3175 */ 3180 3176 if (TSN_lt(ctsn, asoc->ctsn_ack_point)) { 3181 - SCTP_DEBUG_PRINTK("ctsn %x\n", ctsn); 3182 - SCTP_DEBUG_PRINTK("ctsn_ack_point %x\n", asoc->ctsn_ack_point); 3177 + pr_debug("%s: ctsn:%x, ctsn_ack_point:%x\n", __func__, ctsn, 3178 + asoc->ctsn_ack_point); 3179 + 3183 3180 return SCTP_DISPOSITION_DISCARD; 3184 3181 } 3185 3182 ··· 3864 3859 skb_pull(chunk->skb, len); 3865 3860 3866 3861 tsn = ntohl(fwdtsn_hdr->new_cum_tsn); 3867 - SCTP_DEBUG_PRINTK("%s: TSN 0x%x.\n", __func__, tsn); 3862 + pr_debug("%s: TSN 0x%x\n", __func__, tsn); 3868 3863 3869 3864 /* The TSN is too high--silently discard the chunk and count on it 3870 3865 * getting retransmitted later. ··· 3932 3927 skb_pull(chunk->skb, len); 3933 3928 3934 3929 tsn = ntohl(fwdtsn_hdr->new_cum_tsn); 3935 - SCTP_DEBUG_PRINTK("%s: TSN 0x%x.\n", __func__, tsn); 3930 + pr_debug("%s: TSN 0x%x\n", __func__, tsn); 3936 3931 3937 3932 /* The TSN is too high--silently discard the chunk and count on it 3938 3933 * getting retransmitted later. ··· 4171 4166 struct sctp_chunk *err_chunk; 4172 4167 sctp_chunkhdr_t *hdr; 4173 4168 4174 - SCTP_DEBUG_PRINTK("Processing the unknown chunk id %d.\n", type.chunk); 4169 + pr_debug("%s: processing unknown chunk id:%d\n", __func__, type.chunk); 4175 4170 4176 4171 if (!sctp_vtag_verify(unk_chunk, asoc)) 4177 4172 return sctp_sf_pdiscard(net, ep, asoc, type, arg, commands); ··· 4261 4256 return sctp_sf_violation_chunklen(net, ep, asoc, type, arg, 4262 4257 commands); 4263 4258 4264 - SCTP_DEBUG_PRINTK("Chunk %d is discarded\n", type.chunk); 4259 + pr_debug("%s: chunk:%d is discarded\n", __func__, type.chunk); 4260 + 4265 4261 return SCTP_DISPOSITION_DISCARD; 4266 4262 } 4267 4263 ··· 5190 5184 void *arg, 5191 5185 sctp_cmd_seq_t *commands) 5192 5186 { 5193 - SCTP_DEBUG_PRINTK("Primitive type %d is ignored.\n", type.primitive); 5187 + pr_debug("%s: primitive type:%d is ignored\n", __func__, 5188 + type.primitive); 5189 + 5194 5190 return SCTP_DISPOSITION_DISCARD; 5195 5191 } 5196 5192 ··· 5387 5379 void *arg, 5388 5380 sctp_cmd_seq_t *commands) 5389 5381 { 5390 - SCTP_DEBUG_PRINTK("The event other type %d is ignored\n", type.other); 5382 + pr_debug("%s: the event other type:%d is ignored\n", 5383 + __func__, type.other); 5384 + 5391 5385 return SCTP_DISPOSITION_DISCARD; 5392 5386 } 5393 5387 ··· 5537 5527 struct sctp_bind_addr *bp; 5538 5528 int attempts = asoc->init_err_counter + 1; 5539 5529 5540 - SCTP_DEBUG_PRINTK("Timer T1 expired (INIT).\n"); 5530 + pr_debug("%s: timer T1 expired (INIT)\n", __func__); 5531 + 5541 5532 SCTP_INC_STATS(net, SCTP_MIB_T1_INIT_EXPIREDS); 5542 5533 5543 5534 if (attempts <= asoc->max_init_attempts) { ··· 5557 5546 5558 5547 sctp_add_cmd_sf(commands, SCTP_CMD_REPLY, SCTP_CHUNK(repl)); 5559 5548 } else { 5560 - SCTP_DEBUG_PRINTK("Giving up on INIT, attempts: %d" 5561 - " max_init_attempts: %d\n", 5562 - attempts, asoc->max_init_attempts); 5549 + pr_debug("%s: giving up on INIT, attempts:%d " 5550 + "max_init_attempts:%d\n", __func__, attempts, 5551 + asoc->max_init_attempts); 5552 + 5563 5553 sctp_add_cmd_sf(commands, SCTP_CMD_SET_SK_ERR, 5564 5554 SCTP_ERROR(ETIMEDOUT)); 5565 5555 sctp_add_cmd_sf(commands, SCTP_CMD_INIT_FAILED, ··· 5600 5588 struct sctp_chunk *repl = NULL; 5601 5589 int attempts = asoc->init_err_counter + 1; 5602 5590 5603 - SCTP_DEBUG_PRINTK("Timer T1 expired (COOKIE-ECHO).\n"); 5591 + pr_debug("%s: timer T1 expired (COOKIE-ECHO)\n", __func__); 5592 + 5604 5593 SCTP_INC_STATS(net, SCTP_MIB_T1_COOKIE_EXPIREDS); 5605 5594 5606 5595 if (attempts <= asoc->max_init_attempts) { ··· 5649 5636 { 5650 5637 struct sctp_chunk *reply = NULL; 5651 5638 5652 - SCTP_DEBUG_PRINTK("Timer T2 expired.\n"); 5639 + pr_debug("%s: timer T2 expired\n", __func__); 5640 + 5653 5641 SCTP_INC_STATS(net, SCTP_MIB_T2_SHUTDOWN_EXPIREDS); 5654 5642 5655 5643 ((struct sctp_association *)asoc)->shutdown_retries++; ··· 5791 5777 { 5792 5778 struct sctp_chunk *reply = NULL; 5793 5779 5794 - SCTP_DEBUG_PRINTK("Timer T5 expired.\n"); 5780 + pr_debug("%s: timer T5 expired\n", __func__); 5781 + 5795 5782 SCTP_INC_STATS(net, SCTP_MIB_T5_SHUTDOWN_GUARD_EXPIREDS); 5796 5783 5797 5784 reply = sctp_make_abort(asoc, NULL, 0); ··· 5907 5892 void *arg, 5908 5893 sctp_cmd_seq_t *commands) 5909 5894 { 5910 - SCTP_DEBUG_PRINTK("Timer %d ignored.\n", type.chunk); 5895 + pr_debug("%s: timer %d ignored\n", __func__, type.chunk); 5896 + 5911 5897 return SCTP_DISPOSITION_CONSUME; 5912 5898 } 5913 5899 ··· 6118 6102 skb_pull(chunk->skb, sizeof(sctp_datahdr_t)); 6119 6103 6120 6104 tsn = ntohl(data_hdr->tsn); 6121 - SCTP_DEBUG_PRINTK("eat_data: TSN 0x%x.\n", tsn); 6105 + pr_debug("%s: TSN 0x%x\n", __func__, tsn); 6122 6106 6123 6107 /* ASSERT: Now skb->data is really the user data. */ 6124 6108 ··· 6195 6179 */ 6196 6180 if (sctp_tsnmap_has_gap(map) && 6197 6181 (sctp_tsnmap_get_ctsn(map) + 1) == tsn) { 6198 - SCTP_DEBUG_PRINTK("Reneging for tsn:%u\n", tsn); 6182 + pr_debug("%s: reneging for tsn:%u\n", __func__, tsn); 6199 6183 deliver = SCTP_CMD_RENEGE; 6200 6184 } else { 6201 - SCTP_DEBUG_PRINTK("Discard tsn: %u len: %Zd, " 6202 - "rwnd: %d\n", tsn, datalen, 6203 - asoc->rwnd); 6185 + pr_debug("%s: discard tsn:%u len:%zu, rwnd:%d\n", 6186 + __func__, tsn, datalen, asoc->rwnd); 6187 + 6204 6188 return SCTP_IERROR_IGNORE_TSN; 6205 6189 } 6206 6190 } ··· 6215 6199 if (*sk->sk_prot_creator->memory_pressure) { 6216 6200 if (sctp_tsnmap_has_gap(map) && 6217 6201 (sctp_tsnmap_get_ctsn(map) + 1) == tsn) { 6218 - SCTP_DEBUG_PRINTK("Under Pressure! Reneging for tsn:%u\n", tsn); 6202 + pr_debug("%s: under pressure, reneging for tsn:%u\n", 6203 + __func__, tsn); 6219 6204 deliver = SCTP_CMD_RENEGE; 6220 6205 } 6221 6206 }
+81 -89
net/sctp/socket.c
··· 281 281 282 282 sctp_lock_sock(sk); 283 283 284 - SCTP_DEBUG_PRINTK("sctp_bind(sk: %p, addr: %p, addr_len: %d)\n", 285 - sk, addr, addr_len); 284 + pr_debug("%s: sk:%p, addr:%p, addr_len:%d\n", __func__, sk, 285 + addr, addr_len); 286 286 287 287 /* Disallow binding twice. */ 288 288 if (!sctp_sk(sk)->ep->base.bind_addr.port) ··· 342 342 /* Common sockaddr verification. */ 343 343 af = sctp_sockaddr_af(sp, addr, len); 344 344 if (!af) { 345 - SCTP_DEBUG_PRINTK("sctp_do_bind(sk: %p, newaddr: %p, len: %d) EINVAL\n", 346 - sk, addr, len); 345 + pr_debug("%s: sk:%p, newaddr:%p, len:%d EINVAL\n", 346 + __func__, sk, addr, len); 347 347 return -EINVAL; 348 348 } 349 349 350 350 snum = ntohs(addr->v4.sin_port); 351 351 352 - SCTP_DEBUG_PRINTK_IPADDR("sctp_do_bind(sk: %p, new addr: ", 353 - ", port: %d, new port: %d, len: %d)\n", 354 - sk, 355 - addr, 356 - bp->port, snum, 357 - len); 352 + pr_debug("%s: sk:%p, new addr:%pISc, port:%d, new port:%d, len:%d\n", 353 + __func__, sk, &addr->sa, bp->port, snum, len); 358 354 359 355 /* PF specific bind() address verification. */ 360 356 if (!sp->pf->bind_verify(sp, addr)) ··· 364 368 if (!snum) 365 369 snum = bp->port; 366 370 else if (snum != bp->port) { 367 - SCTP_DEBUG_PRINTK("sctp_do_bind:" 368 - " New port %d does not match existing port " 369 - "%d.\n", snum, bp->port); 371 + pr_debug("%s: new port %d doesn't match existing port " 372 + "%d\n", __func__, snum, bp->port); 370 373 return -EINVAL; 371 374 } 372 375 } ··· 463 468 struct sockaddr *sa_addr; 464 469 struct sctp_af *af; 465 470 466 - SCTP_DEBUG_PRINTK("sctp_bindx_add (sk: %p, addrs: %p, addrcnt: %d)\n", 467 - sk, addrs, addrcnt); 471 + pr_debug("%s: sk:%p, addrs:%p, addrcnt:%d\n", __func__, sk, 472 + addrs, addrcnt); 468 473 469 474 addr_buf = addrs; 470 475 for (cnt = 0; cnt < addrcnt; cnt++) { ··· 530 535 sp = sctp_sk(sk); 531 536 ep = sp->ep; 532 537 533 - SCTP_DEBUG_PRINTK("%s: (sk: %p, addrs: %p, addrcnt: %d)\n", 534 - __func__, sk, addrs, addrcnt); 538 + pr_debug("%s: sk:%p, addrs:%p, addrcnt:%d\n", 539 + __func__, sk, addrs, addrcnt); 535 540 536 541 list_for_each_entry(asoc, &ep->asocs, asocs) { 537 - 538 542 if (!asoc->peer.asconf_capable) 539 543 continue; 540 544 ··· 640 646 union sctp_addr *sa_addr; 641 647 struct sctp_af *af; 642 648 643 - SCTP_DEBUG_PRINTK("sctp_bindx_rem (sk: %p, addrs: %p, addrcnt: %d)\n", 644 - sk, addrs, addrcnt); 649 + pr_debug("%s: sk:%p, addrs:%p, addrcnt:%d\n", 650 + __func__, sk, addrs, addrcnt); 645 651 646 652 addr_buf = addrs; 647 653 for (cnt = 0; cnt < addrcnt; cnt++) { ··· 734 740 sp = sctp_sk(sk); 735 741 ep = sp->ep; 736 742 737 - SCTP_DEBUG_PRINTK("%s: (sk: %p, addrs: %p, addrcnt: %d)\n", 738 - __func__, sk, addrs, addrcnt); 743 + pr_debug("%s: sk:%p, addrs:%p, addrcnt:%d\n", 744 + __func__, sk, addrs, addrcnt); 739 745 740 746 list_for_each_entry(asoc, &ep->asocs, asocs) { 741 747 ··· 802 808 sin6 = (struct sockaddr_in6 *)addrs; 803 809 asoc->asconf_addr_del_pending->v6.sin6_addr = sin6->sin6_addr; 804 810 } 805 - SCTP_DEBUG_PRINTK_IPADDR("send_asconf_del_ip: keep the last address asoc: %p ", 806 - " at %p\n", asoc, asoc->asconf_addr_del_pending, 807 - asoc->asconf_addr_del_pending); 811 + 812 + pr_debug("%s: keep the last address asoc:%p %pISc at %p\n", 813 + __func__, asoc, &asoc->asconf_addr_del_pending->sa, 814 + asoc->asconf_addr_del_pending); 815 + 808 816 asoc->src_out_of_asoc_ok = 1; 809 817 stored = 1; 810 818 goto skip_mkasconf; ··· 968 972 void *addr_buf; 969 973 struct sctp_af *af; 970 974 971 - SCTP_DEBUG_PRINTK("sctp_setsockopt_bindx: sk %p addrs %p" 972 - " addrs_size %d opt %d\n", sk, addrs, addrs_size, op); 975 + pr_debug("%s: sk:%p addrs:%p addrs_size:%d opt:%d\n", 976 + __func__, sk, addrs, addrs_size, op); 973 977 974 978 if (unlikely(addrs_size <= 0)) 975 979 return -EINVAL; ··· 1227 1231 asoc = NULL; 1228 1232 1229 1233 out_free: 1234 + pr_debug("%s: took out_free path with asoc:%p kaddrs:%p err:%d\n", 1235 + __func__, asoc, kaddrs, err); 1230 1236 1231 - SCTP_DEBUG_PRINTK("About to exit __sctp_connect() free asoc: %p" 1232 - " kaddrs: %p err: %d\n", 1233 - asoc, kaddrs, err); 1234 1237 if (asoc) { 1235 1238 /* sctp_primitive_ASSOCIATE may have added this association 1236 1239 * To the hash table, try to unhash it, just in case, its a noop ··· 1311 1316 int err = 0; 1312 1317 struct sockaddr *kaddrs; 1313 1318 1314 - SCTP_DEBUG_PRINTK("%s - sk %p addrs %p addrs_size %d\n", 1315 - __func__, sk, addrs, addrs_size); 1319 + pr_debug("%s: sk:%p addrs:%p addrs_size:%d\n", 1320 + __func__, sk, addrs, addrs_size); 1316 1321 1317 1322 if (unlikely(addrs_size <= 0)) 1318 1323 return -EINVAL; ··· 1463 1468 struct list_head *pos, *temp; 1464 1469 unsigned int data_was_unread; 1465 1470 1466 - SCTP_DEBUG_PRINTK("sctp_close(sk: 0x%p, timeout:%ld)\n", sk, timeout); 1471 + pr_debug("%s: sk:%p, timeout:%ld\n", __func__, sk, timeout); 1467 1472 1468 1473 sctp_lock_sock(sk); 1469 1474 sk->sk_shutdown = SHUTDOWN_MASK; ··· 1589 1594 struct sctp_datamsg *datamsg; 1590 1595 int msg_flags = msg->msg_flags; 1591 1596 1592 - SCTP_DEBUG_PRINTK("sctp_sendmsg(sk: %p, msg: %p, msg_len: %zu)\n", 1593 - sk, msg, msg_len); 1594 - 1595 1597 err = 0; 1596 1598 sp = sctp_sk(sk); 1597 1599 ep = sp->ep; 1598 1600 1599 - SCTP_DEBUG_PRINTK("Using endpoint: %p.\n", ep); 1601 + pr_debug("%s: sk:%p, msg:%p, msg_len:%zu ep:%p\n", __func__, sk, 1602 + msg, msg_len, ep); 1600 1603 1601 1604 /* We cannot send a message over a TCP-style listening socket. */ 1602 1605 if (sctp_style(sk, TCP) && sctp_sstate(sk, LISTENING)) { ··· 1604 1611 1605 1612 /* Parse out the SCTP CMSGs. */ 1606 1613 err = sctp_msghdr_parse(msg, &cmsgs); 1607 - 1608 1614 if (err) { 1609 - SCTP_DEBUG_PRINTK("msghdr parse err = %x\n", err); 1615 + pr_debug("%s: msghdr parse err:%x\n", __func__, err); 1610 1616 goto out_nounlock; 1611 1617 } 1612 1618 ··· 1637 1645 associd = sinfo->sinfo_assoc_id; 1638 1646 } 1639 1647 1640 - SCTP_DEBUG_PRINTK("msg_len: %zu, sinfo_flags: 0x%x\n", 1641 - msg_len, sinfo_flags); 1648 + pr_debug("%s: msg_len:%zu, sinfo_flags:0x%x\n", __func__, 1649 + msg_len, sinfo_flags); 1642 1650 1643 1651 /* SCTP_EOF or SCTP_ABORT cannot be set on a TCP-style socket. */ 1644 1652 if (sctp_style(sk, TCP) && (sinfo_flags & (SCTP_EOF | SCTP_ABORT))) { ··· 1667 1675 1668 1676 transport = NULL; 1669 1677 1670 - SCTP_DEBUG_PRINTK("About to look up association.\n"); 1678 + pr_debug("%s: about to look up association\n", __func__); 1671 1679 1672 1680 sctp_lock_sock(sk); 1673 1681 ··· 1697 1705 } 1698 1706 1699 1707 if (asoc) { 1700 - SCTP_DEBUG_PRINTK("Just looked up association: %p.\n", asoc); 1708 + pr_debug("%s: just looked up association:%p\n", __func__, asoc); 1701 1709 1702 1710 /* We cannot send a message on a TCP-style SCTP_SS_ESTABLISHED 1703 1711 * socket that has an association in CLOSED state. This can ··· 1710 1718 } 1711 1719 1712 1720 if (sinfo_flags & SCTP_EOF) { 1713 - SCTP_DEBUG_PRINTK("Shutting down association: %p\n", 1714 - asoc); 1721 + pr_debug("%s: shutting down association:%p\n", 1722 + __func__, asoc); 1723 + 1715 1724 sctp_primitive_SHUTDOWN(net, asoc, NULL); 1716 1725 err = 0; 1717 1726 goto out_unlock; ··· 1725 1732 goto out_unlock; 1726 1733 } 1727 1734 1728 - SCTP_DEBUG_PRINTK("Aborting association: %p\n", asoc); 1735 + pr_debug("%s: aborting association:%p\n", 1736 + __func__, asoc); 1737 + 1729 1738 sctp_primitive_ABORT(net, asoc, chunk); 1730 1739 err = 0; 1731 1740 goto out_unlock; ··· 1736 1741 1737 1742 /* Do we need to create the association? */ 1738 1743 if (!asoc) { 1739 - SCTP_DEBUG_PRINTK("There is no association yet.\n"); 1744 + pr_debug("%s: there is no association yet\n", __func__); 1740 1745 1741 1746 if (sinfo_flags & (SCTP_EOF | SCTP_ABORT)) { 1742 1747 err = -EINVAL; ··· 1835 1840 } 1836 1841 1837 1842 /* ASSERT: we have a valid association at this point. */ 1838 - SCTP_DEBUG_PRINTK("We have a valid association.\n"); 1843 + pr_debug("%s: we have a valid association\n", __func__); 1839 1844 1840 1845 if (!sinfo) { 1841 1846 /* If the user didn't specify SNDRCVINFO, make up one with ··· 1904 1909 err = sctp_primitive_ASSOCIATE(net, asoc, NULL); 1905 1910 if (err < 0) 1906 1911 goto out_free; 1907 - SCTP_DEBUG_PRINTK("We associated primitively.\n"); 1912 + 1913 + pr_debug("%s: we associated primitively\n", __func__); 1908 1914 } 1909 1915 1910 1916 /* Break the message into multiple chunks of maximum size. */ ··· 1932 1936 */ 1933 1937 err = sctp_primitive_SEND(net, asoc, datamsg); 1934 1938 /* Did the lower layer accept the chunk? */ 1935 - if (err) 1939 + if (err) { 1936 1940 sctp_datamsg_free(datamsg); 1937 - else 1938 - sctp_datamsg_put(datamsg); 1939 - 1940 - SCTP_DEBUG_PRINTK("We sent primitively.\n"); 1941 - 1942 - if (err) 1943 1941 goto out_free; 1944 - else 1945 - err = msg_len; 1942 + } 1943 + 1944 + pr_debug("%s: we sent primitively\n", __func__); 1945 + 1946 + sctp_datamsg_put(datamsg); 1947 + err = msg_len; 1946 1948 1947 1949 /* If we are already past ASSOCIATE, the lower 1948 1950 * layers are responsible for association cleanup. ··· 2035 2041 int err = 0; 2036 2042 int skb_len; 2037 2043 2038 - SCTP_DEBUG_PRINTK("sctp_recvmsg(%s: %p, %s: %p, %s: %zd, %s: %d, %s: " 2039 - "0x%x, %s: %p)\n", "sk", sk, "msghdr", msg, 2040 - "len", len, "knoblauch", noblock, 2041 - "flags", flags, "addr_len", addr_len); 2044 + pr_debug("%s: sk:%p, msghdr:%p, len:%zd, noblock:%d, flags:0x%x, " 2045 + "addr_len:%p)\n", __func__, sk, msg, len, noblock, flags, 2046 + addr_len); 2042 2047 2043 2048 sctp_lock_sock(sk); 2044 2049 ··· 3079 3086 3080 3087 err = sctp_send_asconf(asoc, chunk); 3081 3088 3082 - SCTP_DEBUG_PRINTK("We set peer primary addr primitively.\n"); 3089 + pr_debug("%s: we set peer primary addr primitively\n", __func__); 3083 3090 3084 3091 return err; 3085 3092 } ··· 3554 3561 { 3555 3562 int retval = 0; 3556 3563 3557 - SCTP_DEBUG_PRINTK("sctp_setsockopt(sk: %p... optname: %d)\n", 3558 - sk, optname); 3564 + pr_debug("%s: sk:%p, optname:%d\n", __func__, sk, optname); 3559 3565 3560 3566 /* I can hardly begin to describe how wrong this is. This is 3561 3567 * so broken as to be worse than useless. The API draft ··· 3716 3724 3717 3725 sctp_lock_sock(sk); 3718 3726 3719 - SCTP_DEBUG_PRINTK("%s - sk: %p, sockaddr: %p, addr_len: %d\n", 3720 - __func__, sk, addr, addr_len); 3727 + pr_debug("%s: sk:%p, sockaddr:%p, addr_len:%d\n", __func__, sk, 3728 + addr, addr_len); 3721 3729 3722 3730 /* Validate addr_len before calling common connect/connectx routine. */ 3723 3731 af = sctp_get_af_specific(addr->sa_family); ··· 3847 3855 struct net *net = sock_net(sk); 3848 3856 struct sctp_sock *sp; 3849 3857 3850 - SCTP_DEBUG_PRINTK("sctp_init_sock(sk: %p)\n", sk); 3858 + pr_debug("%s: sk:%p\n", __func__, sk); 3851 3859 3852 3860 sp = sctp_sk(sk); 3853 3861 ··· 3982 3990 { 3983 3991 struct sctp_sock *sp; 3984 3992 3985 - SCTP_DEBUG_PRINTK("sctp_destroy_sock(sk: %p)\n", sk); 3993 + pr_debug("%s: sk:%p\n", __func__, sk); 3986 3994 3987 3995 /* Release our hold on the endpoint. */ 3988 3996 sp = sctp_sk(sk); ··· 4115 4123 goto out; 4116 4124 } 4117 4125 4118 - SCTP_DEBUG_PRINTK("sctp_getsockopt_sctp_status(%d): %d %d %d\n", 4119 - len, status.sstat_state, status.sstat_rwnd, 4120 - status.sstat_assoc_id); 4126 + pr_debug("%s: len:%d, state:%d, rwnd:%d, assoc_id:%d\n", 4127 + __func__, len, status.sstat_state, status.sstat_rwnd, 4128 + status.sstat_assoc_id); 4121 4129 4122 4130 if (copy_to_user(optval, &status, len)) { 4123 4131 retval = -EFAULT; ··· 4325 4333 return PTR_ERR(newfile); 4326 4334 } 4327 4335 4328 - SCTP_DEBUG_PRINTK("%s: sk: %p newsk: %p sd: %d\n", 4329 - __func__, sk, newsock->sk, retval); 4336 + pr_debug("%s: sk:%p, newsk:%p, sd:%d\n", __func__, sk, newsock->sk, 4337 + retval); 4330 4338 4331 4339 /* Return the fd mapped to the new socket. */ 4332 4340 if (put_user(len, optlen)) { ··· 4459 4467 trans = sctp_addr_id2transport(sk, &params.spp_address, 4460 4468 params.spp_assoc_id); 4461 4469 if (!trans) { 4462 - SCTP_DEBUG_PRINTK("Failed no transport\n"); 4470 + pr_debug("%s: failed no transport\n", __func__); 4463 4471 return -EINVAL; 4464 4472 } 4465 4473 } ··· 4470 4478 */ 4471 4479 asoc = sctp_id2assoc(sk, params.spp_assoc_id); 4472 4480 if (!asoc && params.spp_assoc_id && sctp_style(sk, UDP)) { 4473 - SCTP_DEBUG_PRINTK("Failed no association\n"); 4481 + pr_debug("%s: failed no association\n", __func__); 4474 4482 return -EINVAL; 4475 4483 } 4476 4484 ··· 5690 5698 if (put_user(len, optlen)) 5691 5699 return -EFAULT; 5692 5700 5693 - SCTP_DEBUG_PRINTK("sctp_getsockopt_assoc_stat(%d): %d\n", 5694 - len, sas.sas_assoc_id); 5701 + pr_debug("%s: len:%d, assoc_id:%d\n", __func__, len, sas.sas_assoc_id); 5695 5702 5696 5703 if (copy_to_user(optval, &sas, len)) 5697 5704 return -EFAULT; ··· 5704 5713 int retval = 0; 5705 5714 int len; 5706 5715 5707 - SCTP_DEBUG_PRINTK("sctp_getsockopt(sk: %p... optname: %d)\n", 5708 - sk, optname); 5716 + pr_debug("%s: sk:%p, optname:%d\n", __func__, sk, optname); 5709 5717 5710 5718 /* I can hardly begin to describe how wrong this is. This is 5711 5719 * so broken as to be worse than useless. The API draft ··· 5884 5894 5885 5895 snum = ntohs(addr->v4.sin_port); 5886 5896 5887 - SCTP_DEBUG_PRINTK("sctp_get_port() begins, snum=%d\n", snum); 5897 + pr_debug("%s: begins, snum:%d\n", __func__, snum); 5898 + 5888 5899 sctp_local_bh_disable(); 5889 5900 5890 5901 if (snum == 0) { ··· 5951 5960 int reuse = sk->sk_reuse; 5952 5961 struct sock *sk2; 5953 5962 5954 - SCTP_DEBUG_PRINTK("sctp_get_port() found a possible match\n"); 5963 + pr_debug("%s: found a possible match\n", __func__); 5964 + 5955 5965 if (pp->fastreuse && sk->sk_reuse && 5956 5966 sk->sk_state != SCTP_SS_LISTENING) 5957 5967 goto success; ··· 5982 5990 goto fail_unlock; 5983 5991 } 5984 5992 } 5985 - SCTP_DEBUG_PRINTK("sctp_get_port(): Found a match\n"); 5993 + 5994 + pr_debug("%s: found a match\n", __func__); 5986 5995 } 5987 5996 pp_not_found: 5988 5997 /* If there was a hash table miss, create a new port. */ ··· 6472 6479 6473 6480 timeo = sock_rcvtimeo(sk, noblock); 6474 6481 6475 - SCTP_DEBUG_PRINTK("Timeout: timeo: %ld, MAX: %ld.\n", 6476 - timeo, MAX_SCHEDULE_TIMEOUT); 6482 + pr_debug("%s: timeo:%ld, max:%ld\n", __func__, timeo, 6483 + MAX_SCHEDULE_TIMEOUT); 6477 6484 6478 6485 do { 6479 6486 /* Again only user level code calls this function, ··· 6604 6611 long current_timeo = *timeo_p; 6605 6612 DEFINE_WAIT(wait); 6606 6613 6607 - SCTP_DEBUG_PRINTK("wait_for_sndbuf: asoc=%p, timeo=%ld, msg_len=%zu\n", 6608 - asoc, (long)(*timeo_p), msg_len); 6614 + pr_debug("%s: asoc:%p, timeo:%ld, msg_len:%zu\n", __func__, asoc, 6615 + *timeo_p, msg_len); 6609 6616 6610 6617 /* Increment the association's refcnt. */ 6611 6618 sctp_association_hold(asoc); ··· 6711 6718 long current_timeo = *timeo_p; 6712 6719 DEFINE_WAIT(wait); 6713 6720 6714 - SCTP_DEBUG_PRINTK("%s: asoc=%p, timeo=%ld\n", __func__, asoc, 6715 - (long)(*timeo_p)); 6721 + pr_debug("%s: asoc:%p, timeo:%ld\n", __func__, asoc, *timeo_p); 6716 6722 6717 6723 /* Increment the association's refcnt. */ 6718 6724 sctp_association_hold(asoc);
+24 -25
net/sctp/transport.c
··· 176 176 */ 177 177 static void sctp_transport_destroy(struct sctp_transport *transport) 178 178 { 179 - SCTP_ASSERT(transport->dead, "Transport is not dead", return); 179 + if (unlikely(!transport->dead)) { 180 + WARN(1, "Attempt to destroy undead transport %p!\n", transport); 181 + return; 182 + } 180 183 181 184 call_rcu(&transport->rcu, sctp_transport_destroy_rcu); 182 185 ··· 320 317 /* Update transport's RTO based on the newly calculated RTT. */ 321 318 void sctp_transport_update_rto(struct sctp_transport *tp, __u32 rtt) 322 319 { 323 - /* Check for valid transport. */ 324 - SCTP_ASSERT(tp, "NULL transport", return); 325 - 326 - /* We should not be doing any RTO updates unless rto_pending is set. */ 327 - SCTP_ASSERT(tp->rto_pending, "rto_pending not set", return); 320 + if (unlikely(!tp->rto_pending)) 321 + /* We should not be doing any RTO updates unless rto_pending is set. */ 322 + pr_debug("%s: rto_pending not set on transport %p!\n", __func__, tp); 328 323 329 324 if (tp->rttvar || tp->srtt) { 330 325 struct net *net = sock_net(tp->asoc->base.sk); ··· 378 377 */ 379 378 tp->rto_pending = 0; 380 379 381 - SCTP_DEBUG_PRINTK("%s: transport: %p, rtt: %d, srtt: %d " 382 - "rttvar: %d, rto: %ld\n", __func__, 383 - tp, rtt, tp->srtt, tp->rttvar, tp->rto); 380 + pr_debug("%s: transport:%p, rtt:%d, srtt:%d rttvar:%d, rto:%ld\n", 381 + __func__, tp, rtt, tp->srtt, tp->rttvar, tp->rto); 384 382 } 385 383 386 384 /* This routine updates the transport's cwnd and partial_bytes_acked ··· 433 433 cwnd += pmtu; 434 434 else 435 435 cwnd += bytes_acked; 436 - SCTP_DEBUG_PRINTK("%s: SLOW START: transport: %p, " 437 - "bytes_acked: %d, cwnd: %d, ssthresh: %d, " 438 - "flight_size: %d, pba: %d\n", 439 - __func__, 440 - transport, bytes_acked, cwnd, 441 - ssthresh, flight_size, pba); 436 + 437 + pr_debug("%s: slow start: transport:%p, bytes_acked:%d, " 438 + "cwnd:%d, ssthresh:%d, flight_size:%d, pba:%d\n", 439 + __func__, transport, bytes_acked, cwnd, ssthresh, 440 + flight_size, pba); 442 441 } else { 443 442 /* RFC 2960 7.2.2 Whenever cwnd is greater than ssthresh, 444 443 * upon each SACK arrival that advances the Cumulative TSN Ack ··· 458 459 cwnd += pmtu; 459 460 pba = ((cwnd < pba) ? (pba - cwnd) : 0); 460 461 } 461 - SCTP_DEBUG_PRINTK("%s: CONGESTION AVOIDANCE: " 462 - "transport: %p, bytes_acked: %d, cwnd: %d, " 463 - "ssthresh: %d, flight_size: %d, pba: %d\n", 464 - __func__, 465 - transport, bytes_acked, cwnd, 466 - ssthresh, flight_size, pba); 462 + 463 + pr_debug("%s: congestion avoidance: transport:%p, " 464 + "bytes_acked:%d, cwnd:%d, ssthresh:%d, " 465 + "flight_size:%d, pba:%d\n", __func__, 466 + transport, bytes_acked, cwnd, ssthresh, 467 + flight_size, pba); 467 468 } 468 469 469 470 transport->cwnd = cwnd; ··· 557 558 } 558 559 559 560 transport->partial_bytes_acked = 0; 560 - SCTP_DEBUG_PRINTK("%s: transport: %p reason: %d cwnd: " 561 - "%d ssthresh: %d\n", __func__, 562 - transport, reason, 563 - transport->cwnd, transport->ssthresh); 561 + 562 + pr_debug("%s: transport:%p, reason:%d, cwnd:%d, ssthresh:%d\n", 563 + __func__, transport, reason, transport->cwnd, 564 + transport->ssthresh); 564 565 } 565 566 566 567 /* Apply Max.Burst limit to the congestion window: