Skip to content

Commit

Permalink
rxrpc: Add a tracepoint to follow what recvmsg does
Browse files Browse the repository at this point in the history
Add a tracepoint to follow what recvmsg does within AF_RXRPC.

Signed-off-by: David Howells <dhowells@redhat.com>
  • Loading branch information
David Howells committed Sep 17, 2016
1 parent 58dc63c commit 8499790
Show file tree
Hide file tree
Showing 4 changed files with 91 additions and 8 deletions.
34 changes: 34 additions & 0 deletions include/trace/events/rxrpc.h
Original file line number Diff line number Diff line change
Expand Up @@ -323,6 +323,40 @@ TRACE_EVENT(rxrpc_receive,
__entry->top)
);

TRACE_EVENT(rxrpc_recvmsg,
TP_PROTO(struct rxrpc_call *call, enum rxrpc_recvmsg_trace why,
rxrpc_seq_t seq, unsigned int offset, unsigned int len,
int ret),

TP_ARGS(call, why, seq, offset, len, ret),

TP_STRUCT__entry(
__field(struct rxrpc_call *, call )
__field(enum rxrpc_recvmsg_trace, why )
__field(rxrpc_seq_t, seq )
__field(unsigned int, offset )
__field(unsigned int, len )
__field(int, ret )
),

TP_fast_assign(
__entry->call = call;
__entry->why = why;
__entry->seq = seq;
__entry->offset = offset;
__entry->len = len;
__entry->ret = ret;
),

TP_printk("c=%p %s q=%08x o=%u l=%u ret=%d",
__entry->call,
rxrpc_recvmsg_traces[__entry->why],
__entry->seq,
__entry->offset,
__entry->len,
__entry->ret)
);

#endif /* _TRACE_RXRPC_H */

/* This part must be outside protection */
Expand Down
17 changes: 17 additions & 0 deletions net/rxrpc/ar-internal.h
Original file line number Diff line number Diff line change
Expand Up @@ -617,6 +617,23 @@ enum rxrpc_receive_trace {

extern const char rxrpc_receive_traces[rxrpc_receive__nr_trace][4];

enum rxrpc_recvmsg_trace {
rxrpc_recvmsg_enter,
rxrpc_recvmsg_wait,
rxrpc_recvmsg_dequeue,
rxrpc_recvmsg_hole,
rxrpc_recvmsg_next,
rxrpc_recvmsg_cont,
rxrpc_recvmsg_full,
rxrpc_recvmsg_data_return,
rxrpc_recvmsg_terminal,
rxrpc_recvmsg_to_be_accepted,
rxrpc_recvmsg_return,
rxrpc_recvmsg__nr_trace
};

extern const char rxrpc_recvmsg_traces[rxrpc_recvmsg__nr_trace][5];

extern const char *const rxrpc_pkts[];
extern const char *rxrpc_acks(u8 reason);

Expand Down
14 changes: 14 additions & 0 deletions net/rxrpc/misc.c
Original file line number Diff line number Diff line change
Expand Up @@ -150,3 +150,17 @@ const char rxrpc_receive_traces[rxrpc_receive__nr_trace][4] = {
[rxrpc_receive_rotate] = "ROT",
[rxrpc_receive_end] = "END",
};

const char rxrpc_recvmsg_traces[rxrpc_recvmsg__nr_trace][5] = {
[rxrpc_recvmsg_enter] = "ENTR",
[rxrpc_recvmsg_wait] = "WAIT",
[rxrpc_recvmsg_dequeue] = "DEQU",
[rxrpc_recvmsg_hole] = "HOLE",
[rxrpc_recvmsg_next] = "NEXT",
[rxrpc_recvmsg_cont] = "CONT",
[rxrpc_recvmsg_full] = "FULL",
[rxrpc_recvmsg_data_return] = "DATA",
[rxrpc_recvmsg_terminal] = "TERM",
[rxrpc_recvmsg_to_be_accepted] = "TBAC",
[rxrpc_recvmsg_return] = "RETN",
};
34 changes: 26 additions & 8 deletions net/rxrpc/recvmsg.c
Original file line number Diff line number Diff line change
Expand Up @@ -94,6 +94,8 @@ static int rxrpc_recvmsg_term(struct rxrpc_call *call, struct msghdr *msg)
break;
}

trace_rxrpc_recvmsg(call, rxrpc_recvmsg_terminal, call->rx_hard_ack,
call->rx_pkt_offset, call->rx_pkt_len, ret);
return ret;
}

Expand Down Expand Up @@ -124,6 +126,7 @@ static int rxrpc_recvmsg_new_call(struct rxrpc_sock *rx,
write_unlock(&rx->call_lock);
}

trace_rxrpc_recvmsg(call, rxrpc_recvmsg_to_be_accepted, 1, 0, 0, ret);
return ret;
}

Expand Down Expand Up @@ -310,8 +313,11 @@ static int rxrpc_recvmsg_data(struct socket *sock, struct rxrpc_call *call,
for (seq = hard_ack + 1; before_eq(seq, top); seq++) {
ix = seq & RXRPC_RXTX_BUFF_MASK;
skb = call->rxtx_buffer[ix];
if (!skb)
if (!skb) {
trace_rxrpc_recvmsg(call, rxrpc_recvmsg_hole, seq,
rx_pkt_offset, rx_pkt_len, 0);
break;
}
smp_rmb();
rxrpc_see_skb(skb);
sp = rxrpc_skb(skb);
Expand All @@ -327,10 +333,15 @@ static int rxrpc_recvmsg_data(struct socket *sock, struct rxrpc_call *call,
ret2 = rxrpc_locate_data(call, skb,
&call->rxtx_annotations[ix],
&rx_pkt_offset, &rx_pkt_len);
trace_rxrpc_recvmsg(call, rxrpc_recvmsg_next, seq,
rx_pkt_offset, rx_pkt_len, ret2);
if (ret2 < 0) {
ret = ret2;
goto out;
}
} else {
trace_rxrpc_recvmsg(call, rxrpc_recvmsg_cont, seq,
rx_pkt_offset, rx_pkt_len, 0);
}
_debug("recvmsg %x DATA #%u { %d, %d }",
sp->hdr.callNumber, seq, rx_pkt_offset, rx_pkt_len);
Expand All @@ -357,6 +368,8 @@ static int rxrpc_recvmsg_data(struct socket *sock, struct rxrpc_call *call,
}

if (rx_pkt_len > 0) {
trace_rxrpc_recvmsg(call, rxrpc_recvmsg_full, seq,
rx_pkt_offset, rx_pkt_len, 0);
_debug("buffer full");
ASSERTCMP(*_offset, ==, len);
ret = 0;
Expand All @@ -383,6 +396,8 @@ static int rxrpc_recvmsg_data(struct socket *sock, struct rxrpc_call *call,
call->rx_pkt_len = rx_pkt_len;
}
done:
trace_rxrpc_recvmsg(call, rxrpc_recvmsg_data_return, seq,
rx_pkt_offset, rx_pkt_len, ret);
_leave(" = %d [%u/%u]", ret, seq, top);
return ret;
}
Expand All @@ -404,7 +419,7 @@ int rxrpc_recvmsg(struct socket *sock, struct msghdr *msg, size_t len,

DEFINE_WAIT(wait);

_enter(",,,%zu,%d", len, flags);
trace_rxrpc_recvmsg(NULL, rxrpc_recvmsg_enter, 0, 0, 0, 0);

if (flags & (MSG_OOB | MSG_TRUNC))
return -EOPNOTSUPP;
Expand All @@ -424,8 +439,10 @@ int rxrpc_recvmsg(struct socket *sock, struct msghdr *msg, size_t len,

if (list_empty(&rx->recvmsg_q)) {
ret = -EWOULDBLOCK;
if (timeo == 0)
if (timeo == 0) {
call = NULL;
goto error_no_call;
}

release_sock(&rx->sk);

Expand All @@ -439,6 +456,8 @@ int rxrpc_recvmsg(struct socket *sock, struct msghdr *msg, size_t len,
if (list_empty(&rx->recvmsg_q)) {
if (signal_pending(current))
goto wait_interrupted;
trace_rxrpc_recvmsg(NULL, rxrpc_recvmsg_wait,
0, 0, 0, 0);
timeo = schedule_timeout(timeo);
}
finish_wait(sk_sleep(&rx->sk), &wait);
Expand All @@ -457,7 +476,7 @@ int rxrpc_recvmsg(struct socket *sock, struct msghdr *msg, size_t len,
rxrpc_get_call(call, rxrpc_call_got);
write_unlock_bh(&rx->recvmsg_lock);

_debug("recvmsg call %p", call);
trace_rxrpc_recvmsg(call, rxrpc_recvmsg_dequeue, 0, 0, 0, 0);

if (test_bit(RXRPC_CALL_RELEASED, &call->flags))
BUG();
Expand Down Expand Up @@ -527,16 +546,15 @@ int rxrpc_recvmsg(struct socket *sock, struct msghdr *msg, size_t len,
rxrpc_put_call(call, rxrpc_call_put);
error_no_call:
release_sock(&rx->sk);
_leave(" = %d", ret);
trace_rxrpc_recvmsg(call, rxrpc_recvmsg_return, 0, 0, 0, ret);
return ret;

wait_interrupted:
ret = sock_intr_errno(timeo);
wait_error:
finish_wait(sk_sleep(&rx->sk), &wait);
release_sock(&rx->sk);
_leave(" = %d [wait]", ret);
return ret;
call = NULL;
goto error_no_call;
}

/**
Expand Down

0 comments on commit 8499790

Please sign in to comment.