From b54a134a7de461f804cf0e28331d0a43ee82fb13 Mon Sep 17 00:00:00 2001 From: David Howells Date: Thu, 5 Jan 2017 10:38:33 +0000 Subject: rxrpc: Fix handling of enums-to-string translation in tracing Fix the way enum values are translated into strings in AF_RXRPC tracepoints. The problem with just doing a lookup in a normal flat array of strings or chars is that external tracing infrastructure can't find it. Rather, TRACE_DEFINE_ENUM must be used. Also sort the enums and string tables to make it easier to keep them in order so that a future patch to __print_symbolic() can be optimised to try a direct lookup into the table first before iterating over it. A couple of _proto() macro calls are removed because they refered to tables that got moved to the tracing infrastructure. The relevant data can be found by way of tracing. Signed-off-by: David Howells --- include/trace/events/rxrpc.h | 424 ++++++++++++++++++++++++++++++++++++++++--- 1 file changed, 403 insertions(+), 21 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h index 0383e5e9a0f3..2395a57462c9 100644 --- a/include/trace/events/rxrpc.h +++ b/include/trace/events/rxrpc.h @@ -16,6 +16,386 @@ #include +/* + * Define enums for tracing information. + * + * These should all be kept sorted, making it easier to match the string + * mapping tables further on. + */ +#ifndef __RXRPC_DECLARE_TRACE_ENUMS_ONCE_ONLY +#define __RXRPC_DECLARE_TRACE_ENUMS_ONCE_ONLY + +enum rxrpc_skb_trace { + rxrpc_skb_rx_cleaned, + rxrpc_skb_rx_freed, + rxrpc_skb_rx_got, + rxrpc_skb_rx_lost, + rxrpc_skb_rx_purged, + rxrpc_skb_rx_received, + rxrpc_skb_rx_rotated, + rxrpc_skb_rx_seen, + rxrpc_skb_tx_cleaned, + rxrpc_skb_tx_freed, + rxrpc_skb_tx_got, + rxrpc_skb_tx_new, + rxrpc_skb_tx_rotated, + rxrpc_skb_tx_seen, +}; + +enum rxrpc_conn_trace { + rxrpc_conn_got, + rxrpc_conn_new_client, + rxrpc_conn_new_service, + rxrpc_conn_put_client, + rxrpc_conn_put_service, + rxrpc_conn_queued, + rxrpc_conn_seen, +}; + +enum rxrpc_client_trace { + rxrpc_client_activate_chans, + rxrpc_client_alloc, + rxrpc_client_chan_activate, + rxrpc_client_chan_disconnect, + rxrpc_client_chan_pass, + rxrpc_client_chan_unstarted, + rxrpc_client_cleanup, + rxrpc_client_count, + rxrpc_client_discard, + rxrpc_client_duplicate, + rxrpc_client_exposed, + rxrpc_client_replace, + rxrpc_client_to_active, + rxrpc_client_to_culled, + rxrpc_client_to_idle, + rxrpc_client_to_inactive, + rxrpc_client_to_upgrade, + rxrpc_client_to_waiting, + rxrpc_client_uncount, +}; + +enum rxrpc_call_trace { + rxrpc_call_connected, + rxrpc_call_error, + rxrpc_call_got, + rxrpc_call_got_kernel, + rxrpc_call_got_userid, + rxrpc_call_new_client, + rxrpc_call_new_service, + rxrpc_call_put, + rxrpc_call_put_kernel, + rxrpc_call_put_noqueue, + rxrpc_call_put_userid, + rxrpc_call_queued, + rxrpc_call_queued_ref, + rxrpc_call_release, + rxrpc_call_seen, +}; + +enum rxrpc_transmit_trace { + rxrpc_transmit_await_reply, + rxrpc_transmit_end, + rxrpc_transmit_queue, + rxrpc_transmit_queue_last, + rxrpc_transmit_rotate, + rxrpc_transmit_rotate_last, + rxrpc_transmit_wait, +}; + +enum rxrpc_receive_trace { + rxrpc_receive_end, + rxrpc_receive_front, + rxrpc_receive_incoming, + rxrpc_receive_queue, + rxrpc_receive_queue_last, + rxrpc_receive_rotate, +}; + +enum rxrpc_recvmsg_trace { + rxrpc_recvmsg_cont, + rxrpc_recvmsg_data_return, + rxrpc_recvmsg_dequeue, + rxrpc_recvmsg_enter, + rxrpc_recvmsg_full, + rxrpc_recvmsg_hole, + rxrpc_recvmsg_next, + rxrpc_recvmsg_return, + rxrpc_recvmsg_terminal, + rxrpc_recvmsg_to_be_accepted, + rxrpc_recvmsg_wait, +}; + +enum rxrpc_rtt_tx_trace { + rxrpc_rtt_tx_data, + rxrpc_rtt_tx_ping, +}; + +enum rxrpc_rtt_rx_trace { + rxrpc_rtt_rx_ping_response, + rxrpc_rtt_rx_requested_ack, +}; + +enum rxrpc_timer_trace { + rxrpc_timer_begin, + rxrpc_timer_expired, + rxrpc_timer_init_for_reply, + rxrpc_timer_init_for_send_reply, + rxrpc_timer_set_for_ack, + rxrpc_timer_set_for_ping, + rxrpc_timer_set_for_resend, + rxrpc_timer_set_for_send, +}; + +enum rxrpc_propose_ack_trace { + rxrpc_propose_ack_client_tx_end, + rxrpc_propose_ack_input_data, + rxrpc_propose_ack_ping_for_lost_ack, + rxrpc_propose_ack_ping_for_lost_reply, + rxrpc_propose_ack_ping_for_params, + rxrpc_propose_ack_processing_op, + rxrpc_propose_ack_respond_to_ack, + rxrpc_propose_ack_respond_to_ping, + rxrpc_propose_ack_retry_tx, + rxrpc_propose_ack_rotate_rx, + rxrpc_propose_ack_terminal_ack, +}; + +enum rxrpc_propose_ack_outcome { + rxrpc_propose_ack_subsume, + rxrpc_propose_ack_update, + rxrpc_propose_ack_use, +}; + +enum rxrpc_congest_change { + rxrpc_cong_begin_retransmission, + rxrpc_cong_cleared_nacks, + rxrpc_cong_new_low_nack, + rxrpc_cong_no_change, + rxrpc_cong_progress, + rxrpc_cong_retransmit_again, + rxrpc_cong_rtt_window_end, + rxrpc_cong_saw_nack, +}; + +#endif /* end __RXRPC_DECLARE_TRACE_ENUMS_ONCE_ONLY */ + +/* + * Declare tracing information enums and their string mappings for display. + */ +#define rxrpc_skb_traces \ + EM(rxrpc_skb_rx_cleaned, "Rx CLN") \ + EM(rxrpc_skb_rx_freed, "Rx FRE") \ + EM(rxrpc_skb_rx_got, "Rx GOT") \ + EM(rxrpc_skb_rx_lost, "Rx *L*") \ + EM(rxrpc_skb_rx_purged, "Rx PUR") \ + EM(rxrpc_skb_rx_received, "Rx RCV") \ + EM(rxrpc_skb_rx_rotated, "Rx ROT") \ + EM(rxrpc_skb_rx_seen, "Rx SEE") \ + EM(rxrpc_skb_tx_cleaned, "Tx CLN") \ + EM(rxrpc_skb_tx_freed, "Tx FRE") \ + EM(rxrpc_skb_tx_got, "Tx GOT") \ + EM(rxrpc_skb_tx_new, "Tx NEW") \ + EM(rxrpc_skb_tx_rotated, "Tx ROT") \ + E_(rxrpc_skb_tx_seen, "Tx SEE") + +#define rxrpc_conn_traces \ + EM(rxrpc_conn_got, "GOT") \ + EM(rxrpc_conn_new_client, "NWc") \ + EM(rxrpc_conn_new_service, "NWs") \ + EM(rxrpc_conn_put_client, "PTc") \ + EM(rxrpc_conn_put_service, "PTs") \ + EM(rxrpc_conn_queued, "QUE") \ + E_(rxrpc_conn_seen, "SEE") + +#define rxrpc_client_traces \ + EM(rxrpc_client_activate_chans, "Activa") \ + EM(rxrpc_client_alloc, "Alloc ") \ + EM(rxrpc_client_chan_activate, "ChActv") \ + EM(rxrpc_client_chan_disconnect, "ChDisc") \ + EM(rxrpc_client_chan_pass, "ChPass") \ + EM(rxrpc_client_chan_unstarted, "ChUnst") \ + EM(rxrpc_client_cleanup, "Clean ") \ + EM(rxrpc_client_count, "Count ") \ + EM(rxrpc_client_discard, "Discar") \ + EM(rxrpc_client_duplicate, "Duplic") \ + EM(rxrpc_client_exposed, "Expose") \ + EM(rxrpc_client_replace, "Replac") \ + EM(rxrpc_client_to_active, "->Actv") \ + EM(rxrpc_client_to_culled, "->Cull") \ + EM(rxrpc_client_to_idle, "->Idle") \ + EM(rxrpc_client_to_inactive, "->Inac") \ + EM(rxrpc_client_to_upgrade, "->Upgd") \ + EM(rxrpc_client_to_waiting, "->Wait") \ + E_(rxrpc_client_uncount, "Uncoun") + +#define rxrpc_conn_cache_states \ + EM(RXRPC_CONN_CLIENT_INACTIVE, "Inac") \ + EM(RXRPC_CONN_CLIENT_WAITING, "Wait") \ + EM(RXRPC_CONN_CLIENT_ACTIVE, "Actv") \ + EM(RXRPC_CONN_CLIENT_CULLED, "Cull") \ + E_(RXRPC_CONN_CLIENT_IDLE, "Idle") \ + +#define rxrpc_call_traces \ + EM(rxrpc_call_connected, "CON") \ + EM(rxrpc_call_error, "*E*") \ + EM(rxrpc_call_got, "GOT") \ + EM(rxrpc_call_got_kernel, "Gke") \ + EM(rxrpc_call_got_userid, "Gus") \ + EM(rxrpc_call_new_client, "NWc") \ + EM(rxrpc_call_new_service, "NWs") \ + EM(rxrpc_call_put, "PUT") \ + EM(rxrpc_call_put_kernel, "Pke") \ + EM(rxrpc_call_put_noqueue, "PNQ") \ + EM(rxrpc_call_put_userid, "Pus") \ + EM(rxrpc_call_queued, "QUE") \ + EM(rxrpc_call_queued_ref, "QUR") \ + EM(rxrpc_call_release, "RLS") \ + E_(rxrpc_call_seen, "SEE") + +#define rxrpc_transmit_traces \ + EM(rxrpc_transmit_await_reply, "AWR") \ + EM(rxrpc_transmit_end, "END") \ + EM(rxrpc_transmit_queue, "QUE") \ + EM(rxrpc_transmit_queue_last, "QLS") \ + EM(rxrpc_transmit_rotate, "ROT") \ + EM(rxrpc_transmit_rotate_last, "RLS") \ + E_(rxrpc_transmit_wait, "WAI") + +#define rxrpc_receive_traces \ + EM(rxrpc_receive_end, "END") \ + EM(rxrpc_receive_front, "FRN") \ + EM(rxrpc_receive_incoming, "INC") \ + EM(rxrpc_receive_queue, "QUE") \ + EM(rxrpc_receive_queue_last, "QLS") \ + E_(rxrpc_receive_rotate, "ROT") + +#define rxrpc_recvmsg_traces \ + EM(rxrpc_recvmsg_cont, "CONT") \ + EM(rxrpc_recvmsg_data_return, "DATA") \ + EM(rxrpc_recvmsg_dequeue, "DEQU") \ + EM(rxrpc_recvmsg_enter, "ENTR") \ + EM(rxrpc_recvmsg_full, "FULL") \ + EM(rxrpc_recvmsg_hole, "HOLE") \ + EM(rxrpc_recvmsg_next, "NEXT") \ + EM(rxrpc_recvmsg_return, "RETN") \ + EM(rxrpc_recvmsg_terminal, "TERM") \ + EM(rxrpc_recvmsg_to_be_accepted, "TBAC") \ + E_(rxrpc_recvmsg_wait, "WAIT") + +#define rxrpc_rtt_tx_traces \ + EM(rxrpc_rtt_tx_data, "DATA") \ + E_(rxrpc_rtt_tx_ping, "PING") + +#define rxrpc_rtt_rx_traces \ + EM(rxrpc_rtt_rx_ping_response, "PONG") \ + E_(rxrpc_rtt_rx_requested_ack, "RACK") + +#define rxrpc_timer_traces \ + EM(rxrpc_timer_begin, "Begin ") \ + EM(rxrpc_timer_expired, "*EXPR*") \ + EM(rxrpc_timer_init_for_reply, "IniRpl") \ + EM(rxrpc_timer_init_for_send_reply, "SndRpl") \ + EM(rxrpc_timer_set_for_ack, "SetAck") \ + EM(rxrpc_timer_set_for_ping, "SetPng") \ + EM(rxrpc_timer_set_for_resend, "SetRTx") \ + E_(rxrpc_timer_set_for_send, "SetTx ") + +#define rxrpc_propose_ack_traces \ + EM(rxrpc_propose_ack_client_tx_end, "ClTxEnd") \ + EM(rxrpc_propose_ack_input_data, "DataIn ") \ + EM(rxrpc_propose_ack_ping_for_lost_ack, "LostAck") \ + EM(rxrpc_propose_ack_ping_for_lost_reply, "LostRpl") \ + EM(rxrpc_propose_ack_ping_for_params, "Params ") \ + EM(rxrpc_propose_ack_processing_op, "ProcOp ") \ + EM(rxrpc_propose_ack_respond_to_ack, "Rsp2Ack") \ + EM(rxrpc_propose_ack_respond_to_ping, "Rsp2Png") \ + EM(rxrpc_propose_ack_retry_tx, "RetryTx") \ + EM(rxrpc_propose_ack_rotate_rx, "RxAck ") \ + E_(rxrpc_propose_ack_terminal_ack, "ClTerm ") + +#define rxrpc_propose_ack_outcomes \ + EM(rxrpc_propose_ack_subsume, " Subsume") \ + EM(rxrpc_propose_ack_update, " Update") \ + E_(rxrpc_propose_ack_use, "") + +#define rxrpc_congest_modes \ + EM(RXRPC_CALL_CONGEST_AVOIDANCE, "CongAvoid") \ + EM(RXRPC_CALL_FAST_RETRANSMIT, "FastReTx ") \ + EM(RXRPC_CALL_PACKET_LOSS, "PktLoss ") \ + E_(RXRPC_CALL_SLOW_START, "SlowStart") + +#define rxrpc_congest_changes \ + EM(rxrpc_cong_begin_retransmission, " Retrans") \ + EM(rxrpc_cong_cleared_nacks, " Cleared") \ + EM(rxrpc_cong_new_low_nack, " NewLowN") \ + EM(rxrpc_cong_no_change, "") \ + EM(rxrpc_cong_progress, " Progres") \ + EM(rxrpc_cong_retransmit_again, " ReTxAgn") \ + EM(rxrpc_cong_rtt_window_end, " RttWinE") \ + E_(rxrpc_cong_saw_nack, " SawNack") + +#define rxrpc_pkts \ + EM(0, "?00") \ + EM(RXRPC_PACKET_TYPE_DATA, "DATA") \ + EM(RXRPC_PACKET_TYPE_ACK, "ACK") \ + EM(RXRPC_PACKET_TYPE_BUSY, "BUSY") \ + EM(RXRPC_PACKET_TYPE_ABORT, "ABORT") \ + EM(RXRPC_PACKET_TYPE_ACKALL, "ACKALL") \ + EM(RXRPC_PACKET_TYPE_CHALLENGE, "CHALL") \ + EM(RXRPC_PACKET_TYPE_RESPONSE, "RESP") \ + EM(RXRPC_PACKET_TYPE_DEBUG, "DEBUG") \ + EM(9, "?09") \ + EM(10, "?10") \ + EM(11, "?11") \ + EM(12, "?12") \ + EM(RXRPC_PACKET_TYPE_VERSION, "VERSION") \ + EM(14, "?14") \ + E_(15, "?15") + +#define rxrpc_ack_names \ + EM(0, "-0-") \ + EM(RXRPC_ACK_REQUESTED, "REQ") \ + EM(RXRPC_ACK_DUPLICATE, "DUP") \ + EM(RXRPC_ACK_OUT_OF_SEQUENCE, "OOS") \ + EM(RXRPC_ACK_EXCEEDS_WINDOW, "WIN") \ + EM(RXRPC_ACK_NOSPACE, "MEM") \ + EM(RXRPC_ACK_PING, "PNG") \ + EM(RXRPC_ACK_PING_RESPONSE, "PNR") \ + EM(RXRPC_ACK_DELAY, "DLY") \ + EM(RXRPC_ACK_IDLE, "IDL") \ + E_(RXRPC_ACK__INVALID, "-?-") + +/* + * Export enum symbols via userspace. + */ +#undef EM +#undef E_ +#define EM(a, b) TRACE_DEFINE_ENUM(a); +#define E_(a, b) TRACE_DEFINE_ENUM(a); + +rxrpc_skb_traces; +rxrpc_conn_traces; +rxrpc_client_traces; +rxrpc_call_traces; +rxrpc_transmit_traces; +rxrpc_receive_traces; +rxrpc_recvmsg_traces; +rxrpc_rtt_tx_traces; +rxrpc_rtt_rx_traces; +rxrpc_timer_traces; +rxrpc_propose_ack_traces; +rxrpc_propose_ack_outcomes; +rxrpc_congest_changes; + +/* + * Now redefine the EM() and E_() macros to map the enums to the strings that + * will be printed in the output. + */ +#undef EM +#undef E_ +#define EM(a, b) { a, b }, +#define E_(a, b) { a, b } + TRACE_EVENT(rxrpc_conn, TP_PROTO(struct rxrpc_connection *conn, enum rxrpc_conn_trace op, int usage, const void *where), @@ -38,7 +418,7 @@ TRACE_EVENT(rxrpc_conn, TP_printk("C=%p %s u=%d sp=%pSR", __entry->conn, - rxrpc_conn_traces[__entry->op], + __print_symbolic(__entry->op, rxrpc_conn_traces), __entry->usage, __entry->where) ); @@ -70,8 +450,8 @@ TRACE_EVENT(rxrpc_client, TP_printk("C=%p h=%2d %s %s i=%08x u=%d", __entry->conn, __entry->channel, - rxrpc_client_traces[__entry->op], - rxrpc_conn_cache_states[__entry->cs], + __print_symbolic(__entry->op, rxrpc_client_traces), + __print_symbolic(__entry->cs, rxrpc_conn_cache_states), __entry->cid, __entry->usage) ); @@ -100,7 +480,7 @@ TRACE_EVENT(rxrpc_call, TP_printk("c=%p %s u=%d sp=%pSR a=%p", __entry->call, - rxrpc_call_traces[__entry->op], + __print_symbolic(__entry->op, rxrpc_call_traces), __entry->usage, __entry->where, __entry->aux) @@ -130,7 +510,7 @@ TRACE_EVENT(rxrpc_skb, TP_printk("s=%p %s u=%d m=%d p=%pSR", __entry->skb, - rxrpc_skb_traces[__entry->op], + __print_symbolic(__entry->op, rxrpc_skb_traces), __entry->usage, __entry->mod_count, __entry->where) @@ -154,7 +534,8 @@ TRACE_EVENT(rxrpc_rx_packet, __entry->hdr.callNumber, __entry->hdr.serviceId, __entry->hdr.serial, __entry->hdr.seq, __entry->hdr.type, __entry->hdr.flags, - __entry->hdr.type <= 15 ? rxrpc_pkts[__entry->hdr.type] : "?UNK") + __entry->hdr.type <= 15 ? + __print_symbolic(__entry->hdr.type, rxrpc_pkts) : "?UNK") ); TRACE_EVENT(rxrpc_rx_done, @@ -225,7 +606,7 @@ TRACE_EVENT(rxrpc_transmit, TP_printk("c=%p %s f=%08x n=%u", __entry->call, - rxrpc_transmit_traces[__entry->why], + __print_symbolic(__entry->why, rxrpc_transmit_traces), __entry->tx_hard_ack + 1, __entry->tx_top - __entry->tx_hard_ack) ); @@ -251,7 +632,7 @@ TRACE_EVENT(rxrpc_rx_ack, TP_printk("c=%p %s f=%08x n=%u", __entry->call, - rxrpc_ack_names[__entry->reason], + __print_symbolic(__entry->reason, rxrpc_ack_names), __entry->first, __entry->n_acks) ); @@ -317,7 +698,7 @@ TRACE_EVENT(rxrpc_tx_ack, TP_printk(" c=%p ACK %08x %s f=%08x r=%08x n=%u", __entry->call, __entry->serial, - rxrpc_ack_names[__entry->reason], + __print_symbolic(__entry->reason, rxrpc_ack_names), __entry->ack_first, __entry->ack_serial, __entry->n_acks) @@ -349,7 +730,7 @@ TRACE_EVENT(rxrpc_receive, TP_printk("c=%p %s r=%08x q=%08x w=%08x-%08x", __entry->call, - rxrpc_receive_traces[__entry->why], + __print_symbolic(__entry->why, rxrpc_receive_traces), __entry->serial, __entry->seq, __entry->hard_ack, @@ -383,7 +764,7 @@ TRACE_EVENT(rxrpc_recvmsg, TP_printk("c=%p %s q=%08x o=%u l=%u ret=%d", __entry->call, - rxrpc_recvmsg_traces[__entry->why], + __print_symbolic(__entry->why, rxrpc_recvmsg_traces), __entry->seq, __entry->offset, __entry->len, @@ -410,7 +791,7 @@ TRACE_EVENT(rxrpc_rtt_tx, TP_printk("c=%p %s sr=%08x", __entry->call, - rxrpc_rtt_tx_traces[__entry->why], + __print_symbolic(__entry->why, rxrpc_rtt_tx_traces), __entry->send_serial) ); @@ -443,7 +824,7 @@ TRACE_EVENT(rxrpc_rtt_rx, TP_printk("c=%p %s sr=%08x rr=%08x rtt=%lld nr=%u avg=%lld", __entry->call, - rxrpc_rtt_rx_traces[__entry->why], + __print_symbolic(__entry->why, rxrpc_rtt_rx_traces), __entry->send_serial, __entry->resp_serial, __entry->rtt, @@ -481,7 +862,7 @@ TRACE_EVENT(rxrpc_timer, TP_printk("c=%p %s x=%lld a=%lld r=%lld t=%ld", __entry->call, - rxrpc_timer_traces[__entry->why], + __print_symbolic(__entry->why, rxrpc_timer_traces), ktime_to_ns(ktime_sub(__entry->expire_at, __entry->now)), ktime_to_ns(ktime_sub(__entry->ack_at, __entry->now)), ktime_to_ns(ktime_sub(__entry->resend_at, __entry->now)), @@ -506,7 +887,8 @@ TRACE_EVENT(rxrpc_rx_lose, __entry->hdr.callNumber, __entry->hdr.serviceId, __entry->hdr.serial, __entry->hdr.seq, __entry->hdr.type, __entry->hdr.flags, - __entry->hdr.type <= 15 ? rxrpc_pkts[__entry->hdr.type] : "?UNK") + __entry->hdr.type <= 15 ? + __print_symbolic(__entry->hdr.type, rxrpc_pkts) : "?UNK") ); TRACE_EVENT(rxrpc_propose_ack, @@ -539,12 +921,12 @@ TRACE_EVENT(rxrpc_propose_ack, TP_printk("c=%p %s %s r=%08x i=%u b=%u%s", __entry->call, - rxrpc_propose_ack_traces[__entry->why], - rxrpc_ack_names[__entry->ack_reason], + __print_symbolic(__entry->why, rxrpc_propose_ack_traces), + __print_symbolic(__entry->ack_reason, rxrpc_ack_names), __entry->serial, __entry->immediate, __entry->background, - rxrpc_propose_ack_outcomes[__entry->outcome]) + __print_symbolic(__entry->outcome, rxrpc_propose_ack_outcomes)) ); TRACE_EVENT(rxrpc_retransmit, @@ -603,9 +985,9 @@ TRACE_EVENT(rxrpc_congest, TP_printk("c=%p %08x %s %08x %s cw=%u ss=%u nr=%u,%u nw=%u,%u r=%u b=%u u=%u d=%u l=%x%s%s%s", __entry->call, __entry->ack_serial, - rxrpc_ack_names[__entry->sum.ack_reason], + __print_symbolic(__entry->sum.ack_reason, rxrpc_ack_names), __entry->hard_ack, - rxrpc_congest_modes[__entry->sum.mode], + __print_symbolic(__entry->sum.mode, rxrpc_congest_modes), __entry->sum.cwnd, __entry->sum.ssthresh, __entry->sum.nr_acks, __entry->sum.nr_nacks, @@ -615,7 +997,7 @@ TRACE_EVENT(rxrpc_congest, __entry->sum.cumulative_acks, __entry->sum.dup_acks, __entry->lowest_nak, __entry->sum.new_low_nack ? "!" : "", - rxrpc_congest_changes[__entry->change], + __print_symbolic(__entry->change, rxrpc_congest_changes), __entry->sum.retrans_timeo ? " rTxTo" : "") ); -- cgit v1.2.3-55-g7522 From b1d9f7fde0bb6c143a9a5b9246ea191e28f2c364 Mon Sep 17 00:00:00 2001 From: David Howells Date: Thu, 5 Jan 2017 10:38:34 +0000 Subject: rxrpc: Add some more tracing Add the following extra tracing information: (1) Modify the rxrpc_transmit tracepoint to record the Tx window size as this is varied by the slow-start algorithm. (2) Modify the rxrpc_rx_ack tracepoint to record more information from received ACK packets. (3) Add an rxrpc_rx_data tracepoint to record the information in DATA packets. (4) Add an rxrpc_disconnect_call tracepoint to record call disconnection, including the reason the call was disconnected. (5) Add an rxrpc_improper_term tracepoint to record implicit termination of a call by a client either by starting a new call on a particular connection channel without first transmitting the final ACK for the previous call. Signed-off-by: David Howells --- include/trace/events/rxrpc.h | 94 +++++++++++++++++++++++++++++++++++++++++--- net/rxrpc/conn_object.c | 1 + net/rxrpc/input.c | 6 ++- 3 files changed, 95 insertions(+), 6 deletions(-) (limited to 'include/trace') diff --git a/include/trace/events/rxrpc.h b/include/trace/events/rxrpc.h index 2395a57462c9..593f586545eb 100644 --- a/include/trace/events/rxrpc.h +++ b/include/trace/events/rxrpc.h @@ -595,6 +595,7 @@ TRACE_EVENT(rxrpc_transmit, __field(enum rxrpc_transmit_trace, why ) __field(rxrpc_seq_t, tx_hard_ack ) __field(rxrpc_seq_t, tx_top ) + __field(int, tx_winsize ) ), TP_fast_assign( @@ -602,38 +603,81 @@ TRACE_EVENT(rxrpc_transmit, __entry->why = why; __entry->tx_hard_ack = call->tx_hard_ack; __entry->tx_top = call->tx_top; + __entry->tx_winsize = call->tx_winsize; ), - TP_printk("c=%p %s f=%08x n=%u", + TP_printk("c=%p %s f=%08x n=%u/%u", __entry->call, __print_symbolic(__entry->why, rxrpc_transmit_traces), __entry->tx_hard_ack + 1, - __entry->tx_top - __entry->tx_hard_ack) + __entry->tx_top - __entry->tx_hard_ack, + __entry->tx_winsize) + ); + +TRACE_EVENT(rxrpc_rx_data, + TP_PROTO(struct rxrpc_call *call, rxrpc_seq_t seq, + rxrpc_serial_t serial, u8 flags, u8 anno), + + TP_ARGS(call, seq, serial, flags, anno), + + TP_STRUCT__entry( + __field(struct rxrpc_call *, call ) + __field(rxrpc_seq_t, seq ) + __field(rxrpc_serial_t, serial ) + __field(u8, flags ) + __field(u8, anno ) + ), + + TP_fast_assign( + __entry->call = call; + __entry->seq = seq; + __entry->serial = serial; + __entry->flags = flags; + __entry->anno = anno; + ), + + TP_printk("c=%p DATA %08x q=%08x fl=%02x a=%02x", + __entry->call, + __entry->serial, + __entry->seq, + __entry->flags, + __entry->anno) ); TRACE_EVENT(rxrpc_rx_ack, - TP_PROTO(struct rxrpc_call *call, rxrpc_seq_t first, u8 reason, u8 n_acks), + TP_PROTO(struct rxrpc_call *call, + rxrpc_serial_t serial, rxrpc_serial_t ack_serial, + rxrpc_seq_t first, rxrpc_seq_t prev, u8 reason, u8 n_acks), - TP_ARGS(call, first, reason, n_acks), + TP_ARGS(call, serial, ack_serial, first, prev, reason, n_acks), TP_STRUCT__entry( __field(struct rxrpc_call *, call ) + __field(rxrpc_serial_t, serial ) + __field(rxrpc_serial_t, ack_serial ) __field(rxrpc_seq_t, first ) + __field(rxrpc_seq_t, prev ) __field(u8, reason ) __field(u8, n_acks ) ), TP_fast_assign( __entry->call = call; + __entry->serial = serial; + __entry->ack_serial = ack_serial; __entry->first = first; + __entry->prev = prev; __entry->reason = reason; __entry->n_acks = n_acks; ), - TP_printk("c=%p %s f=%08x n=%u", + TP_printk("c=%p %08x %s r=%08x f=%08x p=%08x n=%u", __entry->call, + __entry->serial, __print_symbolic(__entry->reason, rxrpc_ack_names), + __entry->ack_serial, __entry->first, + __entry->prev, __entry->n_acks) ); @@ -1001,6 +1045,46 @@ TRACE_EVENT(rxrpc_congest, __entry->sum.retrans_timeo ? " rTxTo" : "") ); +TRACE_EVENT(rxrpc_disconnect_call, + TP_PROTO(struct rxrpc_call *call), + + TP_ARGS(call), + + TP_STRUCT__entry( + __field(struct rxrpc_call *, call ) + __field(u32, abort_code ) + ), + + TP_fast_assign( + __entry->call = call; + __entry->abort_code = call->abort_code; + ), + + TP_printk("c=%p ab=%08x", + __entry->call, + __entry->abort_code) + ); + +TRACE_EVENT(rxrpc_improper_term, + TP_PROTO(struct rxrpc_call *call), + + TP_ARGS(call), + + TP_STRUCT__entry( + __field(struct rxrpc_call *, call ) + __field(u32, abort_code ) + ), + + TP_fast_assign( + __entry->call = call; + __entry->abort_code = call->abort_code; + ), + + TP_printk("c=%p ab=%08x", + __entry->call, + __entry->abort_code) + ); + #endif /* _TRACE_RXRPC_H */ /* This part must be outside protection */ diff --git a/net/rxrpc/conn_object.c b/net/rxrpc/conn_object.c index e1e83af47866..b0ecb770fdce 100644 --- a/net/rxrpc/conn_object.c +++ b/net/rxrpc/conn_object.c @@ -173,6 +173,7 @@ void __rxrpc_disconnect_call(struct rxrpc_connection *conn, /* Save the result of the call so that we can repeat it if necessary * through the channel, whilst disposing of the actual call record. */ + trace_rxrpc_disconnect_call(call); chan->last_service_id = call->service_id; if (call->abort_code) { chan->last_abort = call->abort_code; diff --git a/net/rxrpc/input.c b/net/rxrpc/input.c index 7c2abd85def9..78ec33477adf 100644 --- a/net/rxrpc/input.c +++ b/net/rxrpc/input.c @@ -481,6 +481,7 @@ next_subpacket: return rxrpc_proto_abort("LSA", call, seq); } + trace_rxrpc_rx_data(call, seq, serial, flags, annotation); if (before_eq(seq, hard_ack)) { ack = RXRPC_ACK_DUPLICATE; ack_serial = serial; @@ -765,7 +766,9 @@ static void rxrpc_input_ack(struct rxrpc_call *call, struct sk_buff *skb, summary.ack_reason = (buf.ack.reason < RXRPC_ACK__INVALID ? buf.ack.reason : RXRPC_ACK__INVALID); - trace_rxrpc_rx_ack(call, first_soft_ack, summary.ack_reason, nr_acks); + trace_rxrpc_rx_ack(call, sp->hdr.serial, acked_serial, + first_soft_ack, ntohl(buf.ack.previousPacket), + summary.ack_reason, nr_acks); if (buf.ack.reason == RXRPC_ACK_PING_RESPONSE) rxrpc_input_ping_response(call, skb->tstamp, acked_serial, @@ -951,6 +954,7 @@ static void rxrpc_input_implicit_end_call(struct rxrpc_connection *conn, break; } + trace_rxrpc_improper_term(call); __rxrpc_disconnect_call(conn, call); rxrpc_notify_socket(call); } -- cgit v1.2.3-55-g7522 From 8e8d7f13b6d5a93b3d2cf9a4ceaaf923809fd5ac Mon Sep 17 00:00:00 2001 From: David Howells Date: Thu, 5 Jan 2017 10:38:34 +0000 Subject: afs: Add some tracepoints Add three tracepoints to the AFS filesystem: (1) The afs_recv_data tracepoint logs data segments that are extracted from the data received from the peer through afs_extract_data(). (2) The afs_notify_call tracepoint logs notification from AF_RXRPC of data coming in to an asynchronous call. (3) The afs_cb_call tracepoint logs incoming calls that have had their operation ID extracted and mapped into a supported cache manager service call. To make (3) work, the name strings in the afs_call_type struct objects have to be annotated with __tracepoint_string. This is done with the CM_NAME() macro. Further, the AFS call state enum needs a name so that it can be used to declare parameter types. Signed-off-by: David Howells --- fs/afs/cmservice.c | 22 ++++++--- fs/afs/internal.h | 21 +++++---- fs/afs/main.c | 1 + fs/afs/rxrpc.c | 6 +++ include/trace/events/afs.h | 109 +++++++++++++++++++++++++++++++++++++++++++++ 5 files changed, 144 insertions(+), 15 deletions(-) create mode 100644 include/trace/events/afs.h (limited to 'include/trace') diff --git a/fs/afs/cmservice.c b/fs/afs/cmservice.c index d764236072b1..a2e1e02005f6 100644 --- a/fs/afs/cmservice.c +++ b/fs/afs/cmservice.c @@ -25,11 +25,16 @@ static int afs_deliver_cb_probe_uuid(struct afs_call *); static int afs_deliver_cb_tell_me_about_yourself(struct afs_call *); static void afs_cm_destructor(struct afs_call *); +#define CM_NAME(name) \ + const char afs_SRXCB##name##_name[] __tracepoint_string = \ + "CB." #name + /* * CB.CallBack operation type */ +static CM_NAME(CallBack); static const struct afs_call_type afs_SRXCBCallBack = { - .name = "CB.CallBack", + .name = afs_SRXCBCallBack_name, .deliver = afs_deliver_cb_callback, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -38,8 +43,9 @@ static const struct afs_call_type afs_SRXCBCallBack = { /* * CB.InitCallBackState operation type */ +static CM_NAME(InitCallBackState); static const struct afs_call_type afs_SRXCBInitCallBackState = { - .name = "CB.InitCallBackState", + .name = afs_SRXCBInitCallBackState_name, .deliver = afs_deliver_cb_init_call_back_state, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -48,8 +54,9 @@ static const struct afs_call_type afs_SRXCBInitCallBackState = { /* * CB.InitCallBackState3 operation type */ +static CM_NAME(InitCallBackState3); static const struct afs_call_type afs_SRXCBInitCallBackState3 = { - .name = "CB.InitCallBackState3", + .name = afs_SRXCBInitCallBackState3_name, .deliver = afs_deliver_cb_init_call_back_state3, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -58,8 +65,9 @@ static const struct afs_call_type afs_SRXCBInitCallBackState3 = { /* * CB.Probe operation type */ +static CM_NAME(Probe); static const struct afs_call_type afs_SRXCBProbe = { - .name = "CB.Probe", + .name = afs_SRXCBProbe_name, .deliver = afs_deliver_cb_probe, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -68,8 +76,9 @@ static const struct afs_call_type afs_SRXCBProbe = { /* * CB.ProbeUuid operation type */ +static CM_NAME(ProbeUuid); static const struct afs_call_type afs_SRXCBProbeUuid = { - .name = "CB.ProbeUuid", + .name = afs_SRXCBProbeUuid_name, .deliver = afs_deliver_cb_probe_uuid, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, @@ -78,8 +87,9 @@ static const struct afs_call_type afs_SRXCBProbeUuid = { /* * CB.TellMeAboutYourself operation type */ +static CM_NAME(TellMeAboutYourself); static const struct afs_call_type afs_SRXCBTellMeAboutYourself = { - .name = "CB.TellMeAboutYourself", + .name = afs_SRXCBTellMeAboutYourself_name, .deliver = afs_deliver_cb_tell_me_about_yourself, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, diff --git a/fs/afs/internal.h b/fs/afs/internal.h index 6f7a9638ba1a..f71e58fcc2f2 100644 --- a/fs/afs/internal.h +++ b/fs/afs/internal.h @@ -68,6 +68,15 @@ struct afs_wait_mode { extern const struct afs_wait_mode afs_sync_call; extern const struct afs_wait_mode afs_async_call; +enum afs_call_state { + AFS_CALL_REQUESTING, /* request is being sent for outgoing call */ + AFS_CALL_AWAIT_REPLY, /* awaiting reply to outgoing call */ + AFS_CALL_AWAIT_OP_ID, /* awaiting op ID on incoming call */ + AFS_CALL_AWAIT_REQUEST, /* awaiting request data on incoming call */ + AFS_CALL_REPLYING, /* replying to incoming call */ + AFS_CALL_AWAIT_ACK, /* awaiting final ACK of incoming call */ + AFS_CALL_COMPLETE, /* Completed or failed */ +}; /* * a record of an in-progress RxRPC call */ @@ -91,15 +100,7 @@ struct afs_call { pgoff_t first; /* first page in mapping to deal with */ pgoff_t last; /* last page in mapping to deal with */ size_t offset; /* offset into received data store */ - enum { /* call state */ - AFS_CALL_REQUESTING, /* request is being sent for outgoing call */ - AFS_CALL_AWAIT_REPLY, /* awaiting reply to outgoing call */ - AFS_CALL_AWAIT_OP_ID, /* awaiting op ID on incoming call */ - AFS_CALL_AWAIT_REQUEST, /* awaiting request data on incoming call */ - AFS_CALL_REPLYING, /* replying to incoming call */ - AFS_CALL_AWAIT_ACK, /* awaiting final ACK of incoming call */ - AFS_CALL_COMPLETE, /* Completed or failed */ - } state; + enum afs_call_state state; int error; /* error code */ u32 abort_code; /* Remote abort ID or 0 */ unsigned request_size; /* size of request data */ @@ -773,6 +774,8 @@ extern int afs_fsync(struct file *, loff_t, loff_t, int); /* * debug tracing */ +#include + extern unsigned afs_debug; #define dbgprintk(FMT,...) \ diff --git a/fs/afs/main.c b/fs/afs/main.c index 0b187ef3b5b7..f8188feb03ad 100644 --- a/fs/afs/main.c +++ b/fs/afs/main.c @@ -15,6 +15,7 @@ #include #include #include +#define CREATE_TRACE_POINTS #include "internal.h" MODULE_DESCRIPTION("AFS Client File System"); diff --git a/fs/afs/rxrpc.c b/fs/afs/rxrpc.c index 25f05a8d21b1..f26344a8c029 100644 --- a/fs/afs/rxrpc.c +++ b/fs/afs/rxrpc.c @@ -416,6 +416,8 @@ static void afs_deliver_to_call(struct afs_call *call) ret = rxrpc_kernel_recv_data(afs_socket, call->rxcall, NULL, 0, &offset, false, &call->abort_code); + trace_afs_recv_data(call, 0, offset, false, ret); + if (ret == -EINPROGRESS || ret == -EAGAIN) return; if (ret == 1 || ret < 0) { @@ -541,6 +543,7 @@ static void afs_wake_up_async_call(struct sock *sk, struct rxrpc_call *rxcall, { struct afs_call *call = (struct afs_call *)call_user_ID; + trace_afs_notify_call(rxcall, call); call->need_attention = true; queue_work(afs_async_calls, &call->async_work); } @@ -689,6 +692,8 @@ static int afs_deliver_cm_op_id(struct afs_call *call) if (!afs_cm_incoming_call(call)) return -ENOTSUPP; + trace_afs_cb_call(call); + /* pass responsibility for the remainer of this message off to the * cache manager op */ return call->type->deliver(call); @@ -780,6 +785,7 @@ int afs_extract_data(struct afs_call *call, void *buf, size_t count, ret = rxrpc_kernel_recv_data(afs_socket, call->rxcall, buf, count, &call->offset, want_more, &call->abort_code); + trace_afs_recv_data(call, count, call->offset, want_more, ret); if (ret == 0 || ret == -EAGAIN) return ret; diff --git a/include/trace/events/afs.h b/include/trace/events/afs.h new file mode 100644 index 000000000000..845907b04ff4 --- /dev/null +++ b/include/trace/events/afs.h @@ -0,0 +1,109 @@ +/* AFS tracepoints + * + * Copyright (C) 2016 Red Hat, Inc. All Rights Reserved. + * Written by David Howells (dhowells@redhat.com) + * + * This program is free software; you can redistribute it and/or + * modify it under the terms of the GNU General Public Licence + * as published by the Free Software Foundation; either version + * 2 of the Licence, or (at your option) any later version. + */ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM afs + +#if !defined(_TRACE_AFS_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_AFS_H + +#include + +TRACE_EVENT(afs_recv_data, + TP_PROTO(struct afs_call *call, unsigned count, unsigned offset, + bool want_more, int ret), + + TP_ARGS(call, count, offset, want_more, ret), + + TP_STRUCT__entry( + __field(struct rxrpc_call *, rxcall ) + __field(struct afs_call *, call ) + __field(enum afs_call_state, state ) + __field(unsigned int, count ) + __field(unsigned int, offset ) + __field(unsigned short, unmarshall ) + __field(bool, want_more ) + __field(int, ret ) + ), + + TP_fast_assign( + __entry->rxcall = call->rxcall; + __entry->call = call; + __entry->state = call->state; + __entry->unmarshall = call->unmarshall; + __entry->count = count; + __entry->offset = offset; + __entry->want_more = want_more; + __entry->ret = ret; + ), + + TP_printk("c=%p ac=%p s=%u u=%u %u/%u wm=%u ret=%d", + __entry->rxcall, + __entry->call, + __entry->state, __entry->unmarshall, + __entry->offset, __entry->count, + __entry->want_more, __entry->ret) + ); + +TRACE_EVENT(afs_notify_call, + TP_PROTO(struct rxrpc_call *rxcall, struct afs_call *call), + + TP_ARGS(rxcall, call), + + TP_STRUCT__entry( + __field(struct rxrpc_call *, rxcall ) + __field(struct afs_call *, call ) + __field(enum afs_call_state, state ) + __field(unsigned short, unmarshall ) + ), + + TP_fast_assign( + __entry->rxcall = rxcall; + __entry->call = call; + __entry->state = call->state; + __entry->unmarshall = call->unmarshall; + ), + + TP_printk("c=%p ac=%p s=%u u=%u", + __entry->rxcall, + __entry->call, + __entry->state, __entry->unmarshall) + ); + +TRACE_EVENT(afs_cb_call, + TP_PROTO(struct afs_call *call), + + TP_ARGS(call), + + TP_STRUCT__entry( + __field(struct rxrpc_call *, rxcall ) + __field(struct afs_call *, call ) + __field(const char *, name ) + __field(u32, op ) + ), + + TP_fast_assign( + __entry->rxcall = call->rxcall; + __entry->call = call; + __entry->name = call->type->name; + __entry->op = call->operation_ID; + ), + + TP_printk("c=%p ac=%p %s o=%u", + __entry->rxcall, + __entry->call, + __entry->name, + __entry->op) + ); + +#endif /* _TRACE_AFS_H */ + +/* This part must be outside protection */ +#include -- cgit v1.2.3-55-g7522 From 341f741f04beceebcb30daa12ae2e5e52e64e532 Mon Sep 17 00:00:00 2001 From: David Howells Date: Thu, 5 Jan 2017 10:38:36 +0000 Subject: afs: Refcount the afs_call struct A static checker warning occurs in the AFS filesystem: fs/afs/cmservice.c:155 SRXAFSCB_CallBack() error: dereferencing freed memory 'call' due to the reply being sent before we access the server it points to. The act of sending the reply causes the call to be freed if an error occurs (but not if it doesn't). On top of this, the lifetime handling of afs_call structs is fragile because they get passed around through workqueues without any sort of refcounting. Deal with the issues by: (1) Fix the maybe/maybe not nature of the reply sending functions with regards to whether they release the call struct. (2) Refcount the afs_call struct and sort out places that need to get/put references. (3) Pass a ref through the work queue and release (or pass on) that ref in the work function. Care has to be taken because a work queue may already own a ref to the call. (4) Do the cleaning up in the put function only. (5) Simplify module cleanup by always incrementing afs_outstanding_calls whenever a call is allocated. (6) Set the backlog to 0 with kernel_listen() at the beginning of the process of closing the socket to prevent new incoming calls from occurring and to remove the contribution of preallocated calls from afs_outstanding_calls before we wait on it. A tracepoint is also added to monitor the afs_call refcount and lifetime. Reported-by: Dan Carpenter Signed-off-by: David Howells Fixes: 08e0e7c82eea: "[AF_RXRPC]: Make the in-kernel AFS filesystem use AF_RXRPC." --- fs/afs/cmservice.c | 41 ++++++------ fs/afs/internal.h | 9 ++- fs/afs/rxrpc.c | 153 ++++++++++++++++++++++++++++----------------- include/trace/events/afs.h | 75 ++++++++++++++++++++++ 4 files changed, 199 insertions(+), 79 deletions(-) (limited to 'include/trace') diff --git a/fs/afs/cmservice.c b/fs/afs/cmservice.c index a2e1e02005f6..e349a3316303 100644 --- a/fs/afs/cmservice.c +++ b/fs/afs/cmservice.c @@ -24,6 +24,11 @@ static int afs_deliver_cb_callback(struct afs_call *); static int afs_deliver_cb_probe_uuid(struct afs_call *); static int afs_deliver_cb_tell_me_about_yourself(struct afs_call *); static void afs_cm_destructor(struct afs_call *); +static void SRXAFSCB_CallBack(struct work_struct *); +static void SRXAFSCB_InitCallBackState(struct work_struct *); +static void SRXAFSCB_Probe(struct work_struct *); +static void SRXAFSCB_ProbeUuid(struct work_struct *); +static void SRXAFSCB_TellMeAboutYourself(struct work_struct *); #define CM_NAME(name) \ const char afs_SRXCB##name##_name[] __tracepoint_string = \ @@ -38,6 +43,7 @@ static const struct afs_call_type afs_SRXCBCallBack = { .deliver = afs_deliver_cb_callback, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, + .work = SRXAFSCB_CallBack, }; /* @@ -49,6 +55,7 @@ static const struct afs_call_type afs_SRXCBInitCallBackState = { .deliver = afs_deliver_cb_init_call_back_state, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, + .work = SRXAFSCB_InitCallBackState, }; /* @@ -60,6 +67,7 @@ static const struct afs_call_type afs_SRXCBInitCallBackState3 = { .deliver = afs_deliver_cb_init_call_back_state3, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, + .work = SRXAFSCB_InitCallBackState, }; /* @@ -71,6 +79,7 @@ static const struct afs_call_type afs_SRXCBProbe = { .deliver = afs_deliver_cb_probe, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, + .work = SRXAFSCB_Probe, }; /* @@ -82,6 +91,7 @@ static const struct afs_call_type afs_SRXCBProbeUuid = { .deliver = afs_deliver_cb_probe_uuid, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, + .work = SRXAFSCB_ProbeUuid, }; /* @@ -93,6 +103,7 @@ static const struct afs_call_type afs_SRXCBTellMeAboutYourself = { .deliver = afs_deliver_cb_tell_me_about_yourself, .abort_to_error = afs_abort_to_error, .destructor = afs_cm_destructor, + .work = SRXAFSCB_TellMeAboutYourself, }; /* @@ -163,6 +174,7 @@ static void SRXAFSCB_CallBack(struct work_struct *work) afs_send_empty_reply(call); afs_break_callbacks(call->server, call->count, call->request); + afs_put_call(call); _leave(""); } @@ -284,9 +296,7 @@ static int afs_deliver_cb_callback(struct afs_call *call) return -ENOTCONN; call->server = server; - INIT_WORK(&call->work, SRXAFSCB_CallBack); - queue_work(afs_wq, &call->work); - return 0; + return afs_queue_call_work(call); } /* @@ -300,6 +310,7 @@ static void SRXAFSCB_InitCallBackState(struct work_struct *work) afs_init_callback_state(call->server); afs_send_empty_reply(call); + afs_put_call(call); _leave(""); } @@ -330,9 +341,7 @@ static int afs_deliver_cb_init_call_back_state(struct afs_call *call) return -ENOTCONN; call->server = server; - INIT_WORK(&call->work, SRXAFSCB_InitCallBackState); - queue_work(afs_wq, &call->work); - return 0; + return afs_queue_call_work(call); } /* @@ -404,9 +413,7 @@ static int afs_deliver_cb_init_call_back_state3(struct afs_call *call) return -ENOTCONN; call->server = server; - INIT_WORK(&call->work, SRXAFSCB_InitCallBackState); - queue_work(afs_wq, &call->work); - return 0; + return afs_queue_call_work(call); } /* @@ -418,6 +425,7 @@ static void SRXAFSCB_Probe(struct work_struct *work) _enter(""); afs_send_empty_reply(call); + afs_put_call(call); _leave(""); } @@ -437,9 +445,7 @@ static int afs_deliver_cb_probe(struct afs_call *call) /* no unmarshalling required */ call->state = AFS_CALL_REPLYING; - INIT_WORK(&call->work, SRXAFSCB_Probe); - queue_work(afs_wq, &call->work); - return 0; + return afs_queue_call_work(call); } /* @@ -462,6 +468,7 @@ static void SRXAFSCB_ProbeUuid(struct work_struct *work) reply.match = htonl(1); afs_send_simple_reply(call, &reply, sizeof(reply)); + afs_put_call(call); _leave(""); } @@ -520,9 +527,7 @@ static int afs_deliver_cb_probe_uuid(struct afs_call *call) call->state = AFS_CALL_REPLYING; - INIT_WORK(&call->work, SRXAFSCB_ProbeUuid); - queue_work(afs_wq, &call->work); - return 0; + return afs_queue_call_work(call); } /* @@ -584,7 +589,7 @@ static void SRXAFSCB_TellMeAboutYourself(struct work_struct *work) reply.cap.capcount = htonl(1); reply.cap.caps[0] = htonl(AFS_CAP_ERROR_TRANSLATION); afs_send_simple_reply(call, &reply, sizeof(reply)); - + afs_put_call(call); _leave(""); } @@ -604,7 +609,5 @@ static int afs_deliver_cb_tell_me_about_yourself(struct afs_call *call) /* no unmarshalling required */ call->state = AFS_CALL_REPLYING; - INIT_WORK(&call->work, SRXAFSCB_TellMeAboutYourself); - queue_work(afs_wq, &call->work); - return 0; + return afs_queue_call_work(call); } diff --git a/fs/afs/internal.h b/fs/afs/internal.h index b411670d5f67..65504e218d35 100644 --- a/fs/afs/internal.h +++ b/fs/afs/internal.h @@ -66,7 +66,7 @@ enum afs_call_state { struct afs_call { const struct afs_call_type *type; /* type of call */ wait_queue_head_t waitq; /* processes awaiting completion */ - struct work_struct async_work; /* asynchronous work processor */ + struct work_struct async_work; /* async I/O processor */ struct work_struct work; /* actual work processor */ struct rxrpc_call *rxcall; /* RxRPC call handle */ struct key *key; /* security for this call */ @@ -82,6 +82,7 @@ struct afs_call { pgoff_t first; /* first page in mapping to deal with */ pgoff_t last; /* last page in mapping to deal with */ size_t offset; /* offset into received data store */ + atomic_t usage; enum afs_call_state state; int error; /* error code */ u32 abort_code; /* Remote abort ID or 0 */ @@ -115,6 +116,9 @@ struct afs_call_type { /* clean up a call */ void (*destructor)(struct afs_call *call); + + /* Work function */ + void (*work)(struct work_struct *work); }; /* @@ -591,9 +595,12 @@ extern void afs_proc_cell_remove(struct afs_cell *); * rxrpc.c */ extern struct socket *afs_socket; +extern atomic_t afs_outstanding_calls; extern int afs_open_socket(void); extern void afs_close_socket(void); +extern void afs_put_call(struct afs_call *); +extern int afs_queue_call_work(struct afs_call *); extern int afs_make_call(struct in_addr *, struct afs_call *, gfp_t, bool); extern struct afs_call *afs_alloc_flat_call(const struct afs_call_type *, size_t, size_t); diff --git a/fs/afs/rxrpc.c b/fs/afs/rxrpc.c index ec1e41f929d1..95f42872b787 100644 --- a/fs/afs/rxrpc.c +++ b/fs/afs/rxrpc.c @@ -19,9 +19,8 @@ struct socket *afs_socket; /* my RxRPC socket */ static struct workqueue_struct *afs_async_calls; static struct afs_call *afs_spare_incoming_call; -static atomic_t afs_outstanding_calls; +atomic_t afs_outstanding_calls; -static void afs_free_call(struct afs_call *); static void afs_wake_up_call_waiter(struct sock *, struct rxrpc_call *, unsigned long); static int afs_wait_for_call_to_complete(struct afs_call *); static void afs_wake_up_async_call(struct sock *, struct rxrpc_call *, unsigned long); @@ -112,9 +111,11 @@ void afs_close_socket(void) { _enter(""); + kernel_listen(afs_socket, 0); + flush_workqueue(afs_async_calls); + if (afs_spare_incoming_call) { - atomic_inc(&afs_outstanding_calls); - afs_free_call(afs_spare_incoming_call); + afs_put_call(afs_spare_incoming_call); afs_spare_incoming_call = NULL; } @@ -123,7 +124,6 @@ void afs_close_socket(void) TASK_UNINTERRUPTIBLE); _debug("no outstanding calls"); - flush_workqueue(afs_async_calls); kernel_sock_shutdown(afs_socket, SHUT_RDWR); flush_workqueue(afs_async_calls); sock_release(afs_socket); @@ -134,44 +134,79 @@ void afs_close_socket(void) } /* - * free a call + * Allocate a call. */ -static void afs_free_call(struct afs_call *call) +static struct afs_call *afs_alloc_call(const struct afs_call_type *type, + gfp_t gfp) { - _debug("DONE %p{%s} [%d]", - call, call->type->name, atomic_read(&afs_outstanding_calls)); + struct afs_call *call; + int o; - ASSERTCMP(call->rxcall, ==, NULL); - ASSERT(!work_pending(&call->async_work)); - ASSERT(call->type->name != NULL); + call = kzalloc(sizeof(*call), gfp); + if (!call) + return NULL; - kfree(call->request); - kfree(call); + call->type = type; + atomic_set(&call->usage, 1); + INIT_WORK(&call->async_work, afs_process_async_call); + init_waitqueue_head(&call->waitq); - if (atomic_dec_and_test(&afs_outstanding_calls)) - wake_up_atomic_t(&afs_outstanding_calls); + o = atomic_inc_return(&afs_outstanding_calls); + trace_afs_call(call, afs_call_trace_alloc, 1, o, + __builtin_return_address(0)); + return call; } /* - * End a call but do not free it + * Dispose of a reference on a call. */ -static void afs_end_call_nofree(struct afs_call *call) +void afs_put_call(struct afs_call *call) { - if (call->rxcall) { - rxrpc_kernel_end_call(afs_socket, call->rxcall); - call->rxcall = NULL; + int n = atomic_dec_return(&call->usage); + int o = atomic_read(&afs_outstanding_calls); + + trace_afs_call(call, afs_call_trace_put, n + 1, o, + __builtin_return_address(0)); + + ASSERTCMP(n, >=, 0); + if (n == 0) { + ASSERT(!work_pending(&call->async_work)); + ASSERT(call->type->name != NULL); + + if (call->rxcall) { + rxrpc_kernel_end_call(afs_socket, call->rxcall); + call->rxcall = NULL; + } + if (call->type->destructor) + call->type->destructor(call); + + kfree(call->request); + kfree(call); + + o = atomic_dec_return(&afs_outstanding_calls); + trace_afs_call(call, afs_call_trace_free, 0, o, + __builtin_return_address(0)); + if (o == 0) + wake_up_atomic_t(&afs_outstanding_calls); } - if (call->type->destructor) - call->type->destructor(call); } /* - * End a call and free it + * Queue the call for actual work. Returns 0 unconditionally for convenience. */ -static void afs_end_call(struct afs_call *call) +int afs_queue_call_work(struct afs_call *call) { - afs_end_call_nofree(call); - afs_free_call(call); + int u = atomic_inc_return(&call->usage); + + trace_afs_call(call, afs_call_trace_work, u, + atomic_read(&afs_outstanding_calls), + __builtin_return_address(0)); + + INIT_WORK(&call->work, call->type->work); + + if (!queue_work(afs_wq, &call->work)) + afs_put_call(call); + return 0; } /* @@ -182,25 +217,19 @@ struct afs_call *afs_alloc_flat_call(const struct afs_call_type *type, { struct afs_call *call; - call = kzalloc(sizeof(*call), GFP_NOFS); + call = afs_alloc_call(type, GFP_NOFS); if (!call) goto nomem_call; - _debug("CALL %p{%s} [%d]", - call, type->name, atomic_read(&afs_outstanding_calls)); - atomic_inc(&afs_outstanding_calls); - - call->type = type; - call->request_size = request_size; - call->reply_max = reply_max; - if (request_size) { + call->request_size = request_size; call->request = kmalloc(request_size, GFP_NOFS); if (!call->request) goto nomem_free; } if (reply_max) { + call->reply_max = reply_max; call->buffer = kmalloc(reply_max, GFP_NOFS); if (!call->buffer) goto nomem_free; @@ -210,7 +239,7 @@ struct afs_call *afs_alloc_flat_call(const struct afs_call_type *type, return call; nomem_free: - afs_free_call(call); + afs_put_call(call); nomem_call: return NULL; } @@ -315,7 +344,6 @@ int afs_make_call(struct in_addr *addr, struct afs_call *call, gfp_t gfp, atomic_read(&afs_outstanding_calls)); call->async = async; - INIT_WORK(&call->async_work, afs_process_async_call); memset(&srx, 0, sizeof(srx)); srx.srx_family = AF_RXRPC; @@ -378,7 +406,7 @@ int afs_make_call(struct in_addr *addr, struct afs_call *call, gfp_t gfp, error_do_abort: rxrpc_kernel_abort_call(afs_socket, rxcall, RX_USER_ABORT, -ret, "KSD"); error_kill_call: - afs_end_call(call); + afs_put_call(call); _leave(" = %d", ret); return ret; } @@ -448,7 +476,7 @@ static void afs_deliver_to_call(struct afs_call *call) done: if (call->state == AFS_CALL_COMPLETE && call->incoming) - afs_end_call(call); + afs_put_call(call); out: _leave(""); return; @@ -505,7 +533,7 @@ static int afs_wait_for_call_to_complete(struct afs_call *call) } _debug("call complete"); - afs_end_call(call); + afs_put_call(call); _leave(" = %d", ret); return ret; } @@ -529,14 +557,25 @@ static void afs_wake_up_async_call(struct sock *sk, struct rxrpc_call *rxcall, unsigned long call_user_ID) { struct afs_call *call = (struct afs_call *)call_user_ID; + int u; trace_afs_notify_call(rxcall, call); call->need_attention = true; - queue_work(afs_async_calls, &call->async_work); + + u = __atomic_add_unless(&call->usage, 1, 0); + if (u != 0) { + trace_afs_call(call, afs_call_trace_wake, u, + atomic_read(&afs_outstanding_calls), + __builtin_return_address(0)); + + if (!queue_work(afs_async_calls, &call->async_work)) + afs_put_call(call); + } } /* - * delete an asynchronous call + * Delete an asynchronous call. The work item carries a ref to the call struct + * that we need to release. */ static void afs_delete_async_call(struct work_struct *work) { @@ -544,13 +583,14 @@ static void afs_delete_async_call(struct work_struct *work) _enter(""); - afs_free_call(call); + afs_put_call(call); _leave(""); } /* - * perform processing on an asynchronous call + * Perform I/O processing on an asynchronous call. The work item carries a ref + * to the call struct that we either need to release or to pass on. */ static void afs_process_async_call(struct work_struct *work) { @@ -566,15 +606,16 @@ static void afs_process_async_call(struct work_struct *work) if (call->state == AFS_CALL_COMPLETE) { call->reply = NULL; - /* kill the call */ - afs_end_call_nofree(call); - - /* we can't just delete the call because the work item may be - * queued */ + /* We have two refs to release - one from the alloc and one + * queued with the work item - and we can't just deallocate the + * call because the work item may be queued again. + */ call->async_work.func = afs_delete_async_call; - queue_work(afs_async_calls, &call->async_work); + if (!queue_work(afs_async_calls, &call->async_work)) + afs_put_call(call); } + afs_put_call(call); _leave(""); } @@ -594,12 +635,10 @@ static void afs_charge_preallocation(struct work_struct *work) for (;;) { if (!call) { - call = kzalloc(sizeof(struct afs_call), GFP_KERNEL); + call = afs_alloc_call(&afs_RXCMxxxx, GFP_KERNEL); if (!call) break; - INIT_WORK(&call->async_work, afs_process_async_call); - call->type = &afs_RXCMxxxx; call->async = true; call->state = AFS_CALL_AWAIT_OP_ID; init_waitqueue_head(&call->waitq); @@ -624,9 +663,8 @@ static void afs_rx_discard_new_call(struct rxrpc_call *rxcall, { struct afs_call *call = (struct afs_call *)user_call_ID; - atomic_inc(&afs_outstanding_calls); call->rxcall = NULL; - afs_free_call(call); + afs_put_call(call); } /* @@ -635,7 +673,6 @@ static void afs_rx_discard_new_call(struct rxrpc_call *rxcall, static void afs_rx_new_call(struct sock *sk, struct rxrpc_call *rxcall, unsigned long user_call_ID) { - atomic_inc(&afs_outstanding_calls); queue_work(afs_wq, &afs_charge_preallocation_work); } @@ -699,7 +736,6 @@ void afs_send_empty_reply(struct afs_call *call) rxrpc_kernel_abort_call(afs_socket, call->rxcall, RX_USER_ABORT, ENOMEM, "KOO"); default: - afs_end_call(call); _leave(" [error]"); return; } @@ -738,7 +774,6 @@ void afs_send_simple_reply(struct afs_call *call, const void *buf, size_t len) rxrpc_kernel_abort_call(afs_socket, call->rxcall, RX_USER_ABORT, ENOMEM, "KOO"); } - afs_end_call(call); _leave(" [error]"); } diff --git a/include/trace/events/afs.h b/include/trace/events/afs.h index 845907b04ff4..8b95c16b7045 100644 --- a/include/trace/events/afs.h +++ b/include/trace/events/afs.h @@ -16,6 +16,51 @@ #include +/* + * Define enums for tracing information. + */ +#ifndef __AFS_DECLARE_TRACE_ENUMS_ONCE_ONLY +#define __AFS_DECLARE_TRACE_ENUMS_ONCE_ONLY + +enum afs_call_trace { + afs_call_trace_alloc, + afs_call_trace_free, + afs_call_trace_put, + afs_call_trace_wake, + afs_call_trace_work, +}; + +#endif /* end __AFS_DECLARE_TRACE_ENUMS_ONCE_ONLY */ + +/* + * Declare tracing information enums and their string mappings for display. + */ +#define afs_call_traces \ + EM(afs_call_trace_alloc, "ALLOC") \ + EM(afs_call_trace_free, "FREE ") \ + EM(afs_call_trace_put, "PUT ") \ + EM(afs_call_trace_wake, "WAKE ") \ + E_(afs_call_trace_work, "WORK ") + +/* + * Export enum symbols via userspace. + */ +#undef EM +#undef E_ +#define EM(a, b) TRACE_DEFINE_ENUM(a); +#define E_(a, b) TRACE_DEFINE_ENUM(a); + +afs_call_traces; + +/* + * Now redefine the EM() and E_() macros to map the enums to the strings that + * will be printed in the output. + */ +#undef EM +#undef E_ +#define EM(a, b) { a, b }, +#define E_(a, b) { a, b } + TRACE_EVENT(afs_recv_data, TP_PROTO(struct afs_call *call, unsigned count, unsigned offset, bool want_more, int ret), @@ -103,6 +148,36 @@ TRACE_EVENT(afs_cb_call, __entry->op) ); +TRACE_EVENT(afs_call, + TP_PROTO(struct afs_call *call, enum afs_call_trace op, + int usage, int outstanding, const void *where), + + TP_ARGS(call, op, usage, outstanding, where), + + TP_STRUCT__entry( + __field(struct afs_call *, call ) + __field(int, op ) + __field(int, usage ) + __field(int, outstanding ) + __field(const void *, where ) + ), + + TP_fast_assign( + __entry->call = call; + __entry->op = op; + __entry->usage = usage; + __entry->outstanding = outstanding; + __entry->where = where; + ), + + TP_printk("c=%p %s u=%d o=%d sp=%pSR", + __entry->call, + __print_symbolic(__entry->op, afs_call_traces), + __entry->usage, + __entry->outstanding, + __entry->where) + ); + #endif /* _TRACE_AFS_H */ /* This part must be outside protection */ -- cgit v1.2.3-55-g7522 From 2acae0d5b0f73a8fb4b180bd13491feb96e55fc6 Mon Sep 17 00:00:00 2001 From: Daniel Borkmann Date: Wed, 25 Jan 2017 02:28:16 +0100 Subject: trace: add variant without spacing in trace_print_hex_seq For upcoming tracepoint support for BPF, we want to dump the program's tag. Format should be similar to __print_hex(), but without spacing. Add a __print_hex_str() variant for exactly that purpose that reuses trace_print_hex_seq(). Signed-off-by: Daniel Borkmann Cc: Steven Rostedt Cc: Arnaldo Carvalho de Melo Signed-off-by: David S. Miller --- include/linux/trace_events.h | 3 ++- include/trace/trace_events.h | 8 +++++++- kernel/trace/trace_output.c | 7 ++++--- 3 files changed, 13 insertions(+), 5 deletions(-) (limited to 'include/trace') diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h index be007610ceb0..cfa475a0e9ca 100644 --- a/include/linux/trace_events.h +++ b/include/linux/trace_events.h @@ -33,7 +33,8 @@ const char *trace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr, unsigned int bitmask_size); const char *trace_print_hex_seq(struct trace_seq *p, - const unsigned char *buf, int len); + const unsigned char *buf, int len, + bool spacing); const char *trace_print_array_seq(struct trace_seq *p, const void *buf, int count, diff --git a/include/trace/trace_events.h b/include/trace/trace_events.h index 467e12f780d8..9f684629c3cf 100644 --- a/include/trace/trace_events.h +++ b/include/trace/trace_events.h @@ -297,7 +297,12 @@ TRACE_MAKE_SYSTEM_STR(); #endif #undef __print_hex -#define __print_hex(buf, buf_len) trace_print_hex_seq(p, buf, buf_len) +#define __print_hex(buf, buf_len) \ + trace_print_hex_seq(p, buf, buf_len, true) + +#undef __print_hex_str +#define __print_hex_str(buf, buf_len) \ + trace_print_hex_seq(p, buf, buf_len, false) #undef __print_array #define __print_array(array, count, el_size) \ @@ -711,6 +716,7 @@ static inline void ftrace_test_probe_##call(void) \ #undef __print_flags #undef __print_symbolic #undef __print_hex +#undef __print_hex_str #undef __get_dynamic_array #undef __get_dynamic_array_len #undef __get_str diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c index 5d33a7352919..30a144b1b9ee 100644 --- a/kernel/trace/trace_output.c +++ b/kernel/trace/trace_output.c @@ -163,14 +163,15 @@ trace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr, EXPORT_SYMBOL_GPL(trace_print_bitmask_seq); const char * -trace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int buf_len) +trace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int buf_len, + bool spacing) { int i; const char *ret = trace_seq_buffer_ptr(p); for (i = 0; i < buf_len; i++) - trace_seq_printf(p, "%s%2.2x", i == 0 ? "" : " ", buf[i]); - + trace_seq_printf(p, "%s%2.2x", !spacing || i == 0 ? "" : " ", + buf[i]); trace_seq_putc(p, 0); return ret; -- cgit v1.2.3-55-g7522 From a67edbf4fb6deadcfe57a04a134abed4a5ba3bb5 Mon Sep 17 00:00:00 2001 From: Daniel Borkmann Date: Wed, 25 Jan 2017 02:28:18 +0100 Subject: bpf: add initial bpf tracepoints This work adds a number of tracepoints to paths that are either considered slow-path or exception-like states, where monitoring or inspecting them would be desirable. For bpf(2) syscall, tracepoints have been placed for main commands when they succeed. In XDP case, tracepoint is for exceptions, that is, f.e. on abnormal BPF program exit such as unknown or XDP_ABORTED return code, or when error occurs during XDP_TX action and the packet could not be forwarded. Both have been split into separate event headers, and can be further extended. Worst case, if they unexpectedly should get into our way in future, they can also removed [1]. Of course, these tracepoints (like any other) can be analyzed by eBPF itself, etc. Example output: # ./perf record -a -e bpf:* sleep 10 # ./perf script sock_example 6197 [005] 283.980322: bpf:bpf_map_create: map type=ARRAY ufd=4 key=4 val=8 max=256 flags=0 sock_example 6197 [005] 283.980721: bpf:bpf_prog_load: prog=a5ea8fa30ea6849c type=SOCKET_FILTER ufd=5 sock_example 6197 [005] 283.988423: bpf:bpf_prog_get_type: prog=a5ea8fa30ea6849c type=SOCKET_FILTER sock_example 6197 [005] 283.988443: bpf:bpf_map_lookup_elem: map type=ARRAY ufd=4 key=[06 00 00 00] val=[00 00 00 00 00 00 00 00] [...] sock_example 6197 [005] 288.990868: bpf:bpf_map_lookup_elem: map type=ARRAY ufd=4 key=[01 00 00 00] val=[14 00 00 00 00 00 00 00] swapper 0 [005] 289.338243: bpf:bpf_prog_put_rcu: prog=a5ea8fa30ea6849c type=SOCKET_FILTER [1] https://lwn.net/Articles/705270/ Signed-off-by: Daniel Borkmann Acked-by: Alexei Starovoitov Signed-off-by: David S. Miller --- drivers/net/ethernet/mellanox/mlx4/en_rx.c | 3 + drivers/net/ethernet/mellanox/mlx5/core/en_rx.c | 12 +- .../net/ethernet/netronome/nfp/nfp_net_common.c | 15 +- drivers/net/ethernet/qlogic/qede/qede_fp.c | 4 + drivers/net/virtio_net.c | 12 +- include/linux/bpf_trace.h | 7 + include/trace/events/bpf.h | 347 +++++++++++++++++++++ include/trace/events/xdp.h | 53 ++++ kernel/bpf/core.c | 9 + kernel/bpf/inode.c | 17 +- kernel/bpf/syscall.c | 19 +- 11 files changed, 483 insertions(+), 15 deletions(-) create mode 100644 include/linux/bpf_trace.h create mode 100644 include/trace/events/bpf.h create mode 100644 include/trace/events/xdp.h (limited to 'include/trace') diff --git a/drivers/net/ethernet/mellanox/mlx4/en_rx.c b/drivers/net/ethernet/mellanox/mlx4/en_rx.c index e362f99334d0..f15ddba3659a 100644 --- a/drivers/net/ethernet/mellanox/mlx4/en_rx.c +++ b/drivers/net/ethernet/mellanox/mlx4/en_rx.c @@ -33,6 +33,7 @@ #include #include +#include #include #include #include @@ -926,10 +927,12 @@ int mlx4_en_process_rx_cq(struct net_device *dev, struct mlx4_en_cq *cq, int bud length, cq->ring, &doorbell_pending))) goto consumed; + trace_xdp_exception(dev, xdp_prog, act); goto xdp_drop_no_cnt; /* Drop on xmit failure */ default: bpf_warn_invalid_xdp_action(act); case XDP_ABORTED: + trace_xdp_exception(dev, xdp_prog, act); case XDP_DROP: ring->xdp_drop++; xdp_drop_no_cnt: diff --git a/drivers/net/ethernet/mellanox/mlx5/core/en_rx.c b/drivers/net/ethernet/mellanox/mlx5/core/en_rx.c index ba50583ea3ed..3d2e1a1886a5 100644 --- a/drivers/net/ethernet/mellanox/mlx5/core/en_rx.c +++ b/drivers/net/ethernet/mellanox/mlx5/core/en_rx.c @@ -33,6 +33,7 @@ #include #include #include +#include #include #include "en.h" #include "en_tc.h" @@ -640,7 +641,7 @@ static inline void mlx5e_xmit_xdp_doorbell(struct mlx5e_sq *sq) mlx5e_tx_notify_hw(sq, &wqe->ctrl, 0); } -static inline void mlx5e_xmit_xdp_frame(struct mlx5e_rq *rq, +static inline bool mlx5e_xmit_xdp_frame(struct mlx5e_rq *rq, struct mlx5e_dma_info *di, const struct xdp_buff *xdp) { @@ -662,7 +663,7 @@ static inline void mlx5e_xmit_xdp_frame(struct mlx5e_rq *rq, MLX5E_SW2HW_MTU(rq->netdev->mtu) < dma_len)) { rq->stats.xdp_drop++; mlx5e_page_release(rq, di, true); - return; + return false; } if (unlikely(!mlx5e_sq_has_room_for(sq, MLX5E_XDP_TX_WQEBBS))) { @@ -673,7 +674,7 @@ static inline void mlx5e_xmit_xdp_frame(struct mlx5e_rq *rq, } rq->stats.xdp_tx_full++; mlx5e_page_release(rq, di, true); - return; + return false; } dma_len -= MLX5E_XDP_MIN_INLINE; @@ -703,6 +704,7 @@ static inline void mlx5e_xmit_xdp_frame(struct mlx5e_rq *rq, sq->db.xdp.doorbell = true; rq->stats.xdp_tx++; + return true; } /* returns true if packet was consumed by xdp */ @@ -728,11 +730,13 @@ static inline int mlx5e_xdp_handle(struct mlx5e_rq *rq, *len = xdp.data_end - xdp.data; return false; case XDP_TX: - mlx5e_xmit_xdp_frame(rq, di, &xdp); + if (unlikely(!mlx5e_xmit_xdp_frame(rq, di, &xdp))) + trace_xdp_exception(rq->netdev, prog, act); return true; default: bpf_warn_invalid_xdp_action(act); case XDP_ABORTED: + trace_xdp_exception(rq->netdev, prog, act); case XDP_DROP: rq->stats.xdp_drop++; mlx5e_page_release(rq, di, true); diff --git a/drivers/net/ethernet/netronome/nfp/nfp_net_common.c b/drivers/net/ethernet/netronome/nfp/nfp_net_common.c index 67afd95ffb93..6ac43abf561b 100644 --- a/drivers/net/ethernet/netronome/nfp/nfp_net_common.c +++ b/drivers/net/ethernet/netronome/nfp/nfp_net_common.c @@ -42,6 +42,7 @@ */ #include +#include #include #include #include @@ -1459,7 +1460,7 @@ nfp_net_rx_drop(struct nfp_net_r_vector *r_vec, struct nfp_net_rx_ring *rx_ring, dev_kfree_skb_any(skb); } -static void +static bool nfp_net_tx_xdp_buf(struct nfp_net *nn, struct nfp_net_rx_ring *rx_ring, struct nfp_net_tx_ring *tx_ring, struct nfp_net_rx_buf *rxbuf, unsigned int pkt_off, @@ -1473,13 +1474,13 @@ nfp_net_tx_xdp_buf(struct nfp_net *nn, struct nfp_net_rx_ring *rx_ring, if (unlikely(nfp_net_tx_full(tx_ring, 1))) { nfp_net_rx_drop(rx_ring->r_vec, rx_ring, rxbuf, NULL); - return; + return false; } new_frag = nfp_net_napi_alloc_one(nn, DMA_BIDIRECTIONAL, &new_dma_addr); if (unlikely(!new_frag)) { nfp_net_rx_drop(rx_ring->r_vec, rx_ring, rxbuf, NULL); - return; + return false; } nfp_net_rx_give_one(rx_ring, new_frag, new_dma_addr); @@ -1509,6 +1510,7 @@ nfp_net_tx_xdp_buf(struct nfp_net *nn, struct nfp_net_rx_ring *rx_ring, tx_ring->wr_p++; tx_ring->wr_ptr_add++; + return true; } static int nfp_net_run_xdp(struct bpf_prog *prog, void *data, unsigned int len) @@ -1613,12 +1615,15 @@ static int nfp_net_rx(struct nfp_net_rx_ring *rx_ring, int budget) case XDP_PASS: break; case XDP_TX: - nfp_net_tx_xdp_buf(nn, rx_ring, tx_ring, rxbuf, - pkt_off, pkt_len); + if (unlikely(!nfp_net_tx_xdp_buf(nn, rx_ring, + tx_ring, rxbuf, + pkt_off, pkt_len))) + trace_xdp_exception(nn->netdev, xdp_prog, act); continue; default: bpf_warn_invalid_xdp_action(act); case XDP_ABORTED: + trace_xdp_exception(nn->netdev, xdp_prog, act); case XDP_DROP: nfp_net_rx_give_one(rx_ring, rxbuf->frag, rxbuf->dma_addr); diff --git a/drivers/net/ethernet/qlogic/qede/qede_fp.c b/drivers/net/ethernet/qlogic/qede/qede_fp.c index 1a6ca4884fad..445d4d2492c3 100644 --- a/drivers/net/ethernet/qlogic/qede/qede_fp.c +++ b/drivers/net/ethernet/qlogic/qede/qede_fp.c @@ -32,6 +32,7 @@ #include #include #include +#include #include #include #include @@ -1016,6 +1017,7 @@ static bool qede_rx_xdp(struct qede_dev *edev, /* We need the replacement buffer before transmit. */ if (qede_alloc_rx_buffer(rxq, true)) { qede_recycle_rx_bd_ring(rxq, 1); + trace_xdp_exception(edev->ndev, prog, act); return false; } @@ -1026,6 +1028,7 @@ static bool qede_rx_xdp(struct qede_dev *edev, dma_unmap_page(rxq->dev, bd->mapping, PAGE_SIZE, DMA_BIDIRECTIONAL); __free_page(bd->data); + trace_xdp_exception(edev->ndev, prog, act); } /* Regardless, we've consumed an Rx BD */ @@ -1035,6 +1038,7 @@ static bool qede_rx_xdp(struct qede_dev *edev, default: bpf_warn_invalid_xdp_action(act); case XDP_ABORTED: + trace_xdp_exception(edev->ndev, prog, act); case XDP_DROP: qede_recycle_rx_bd_ring(rxq, cqe->bd_num); } diff --git a/drivers/net/virtio_net.c b/drivers/net/virtio_net.c index 37db91d1a0a3..f9bf94887ff1 100644 --- a/drivers/net/virtio_net.c +++ b/drivers/net/virtio_net.c @@ -23,6 +23,7 @@ #include #include #include +#include #include #include #include @@ -330,7 +331,7 @@ static struct sk_buff *page_to_skb(struct virtnet_info *vi, return skb; } -static void virtnet_xdp_xmit(struct virtnet_info *vi, +static bool virtnet_xdp_xmit(struct virtnet_info *vi, struct receive_queue *rq, struct send_queue *sq, struct xdp_buff *xdp, @@ -382,10 +383,12 @@ static void virtnet_xdp_xmit(struct virtnet_info *vi, put_page(page); } else /* small buffer */ kfree_skb(data); - return; // On error abort to avoid unnecessary kick + /* On error abort to avoid unnecessary kick */ + return false; } virtqueue_kick(sq->vq); + return true; } static u32 do_xdp_prog(struct virtnet_info *vi, @@ -421,11 +424,14 @@ static u32 do_xdp_prog(struct virtnet_info *vi, vi->xdp_queue_pairs + smp_processor_id(); xdp.data = buf; - virtnet_xdp_xmit(vi, rq, &vi->sq[qp], &xdp, data); + if (unlikely(!virtnet_xdp_xmit(vi, rq, &vi->sq[qp], &xdp, + data))) + trace_xdp_exception(vi->dev, xdp_prog, act); return XDP_TX; default: bpf_warn_invalid_xdp_action(act); case XDP_ABORTED: + trace_xdp_exception(vi->dev, xdp_prog, act); case XDP_DROP: return XDP_DROP; } diff --git a/include/linux/bpf_trace.h b/include/linux/bpf_trace.h new file mode 100644 index 000000000000..b22efbdd2eb4 --- /dev/null +++ b/include/linux/bpf_trace.h @@ -0,0 +1,7 @@ +#ifndef __LINUX_BPF_TRACE_H__ +#define __LINUX_BPF_TRACE_H__ + +#include +#include + +#endif /* __LINUX_BPF_TRACE_H__ */ diff --git a/include/trace/events/bpf.h b/include/trace/events/bpf.h new file mode 100644 index 000000000000..c3a53fd47ff1 --- /dev/null +++ b/include/trace/events/bpf.h @@ -0,0 +1,347 @@ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM bpf + +#if !defined(_TRACE_BPF_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_BPF_H + +#include +#include +#include +#include + +#define __PROG_TYPE_MAP(FN) \ + FN(SOCKET_FILTER) \ + FN(KPROBE) \ + FN(SCHED_CLS) \ + FN(SCHED_ACT) \ + FN(TRACEPOINT) \ + FN(XDP) \ + FN(PERF_EVENT) \ + FN(CGROUP_SKB) \ + FN(CGROUP_SOCK) \ + FN(LWT_IN) \ + FN(LWT_OUT) \ + FN(LWT_XMIT) + +#define __MAP_TYPE_MAP(FN) \ + FN(HASH) \ + FN(ARRAY) \ + FN(PROG_ARRAY) \ + FN(PERF_EVENT_ARRAY) \ + FN(PERCPU_HASH) \ + FN(PERCPU_ARRAY) \ + FN(STACK_TRACE) \ + FN(CGROUP_ARRAY) \ + FN(LRU_HASH) \ + FN(LRU_PERCPU_HASH) \ + FN(LPM_TRIE) + +#define __PROG_TYPE_TP_FN(x) \ + TRACE_DEFINE_ENUM(BPF_PROG_TYPE_##x); +#define __PROG_TYPE_SYM_FN(x) \ + { BPF_PROG_TYPE_##x, #x }, +#define __PROG_TYPE_SYM_TAB \ + __PROG_TYPE_MAP(__PROG_TYPE_SYM_FN) { -1, 0 } +__PROG_TYPE_MAP(__PROG_TYPE_TP_FN) + +#define __MAP_TYPE_TP_FN(x) \ + TRACE_DEFINE_ENUM(BPF_MAP_TYPE_##x); +#define __MAP_TYPE_SYM_FN(x) \ + { BPF_MAP_TYPE_##x, #x }, +#define __MAP_TYPE_SYM_TAB \ + __MAP_TYPE_MAP(__MAP_TYPE_SYM_FN) { -1, 0 } +__MAP_TYPE_MAP(__MAP_TYPE_TP_FN) + +DECLARE_EVENT_CLASS(bpf_prog_event, + + TP_PROTO(const struct bpf_prog *prg), + + TP_ARGS(prg), + + TP_STRUCT__entry( + __array(u8, prog_tag, 8) + __field(u32, type) + ), + + TP_fast_assign( + BUILD_BUG_ON(sizeof(__entry->prog_tag) != sizeof(prg->tag)); + memcpy(__entry->prog_tag, prg->tag, sizeof(prg->tag)); + __entry->type = prg->type; + ), + + TP_printk("prog=%s type=%s", + __print_hex_str(__entry->prog_tag, 8), + __print_symbolic(__entry->type, __PROG_TYPE_SYM_TAB)) +); + +DEFINE_EVENT(bpf_prog_event, bpf_prog_get_type, + + TP_PROTO(const struct bpf_prog *prg), + + TP_ARGS(prg) +); + +DEFINE_EVENT(bpf_prog_event, bpf_prog_put_rcu, + + TP_PROTO(const struct bpf_prog *prg), + + TP_ARGS(prg) +); + +TRACE_EVENT(bpf_prog_load, + + TP_PROTO(const struct bpf_prog *prg, int ufd), + + TP_ARGS(prg, ufd), + + TP_STRUCT__entry( + __array(u8, prog_tag, 8) + __field(u32, type) + __field(int, ufd) + ), + + TP_fast_assign( + BUILD_BUG_ON(sizeof(__entry->prog_tag) != sizeof(prg->tag)); + memcpy(__entry->prog_tag, prg->tag, sizeof(prg->tag)); + __entry->type = prg->type; + __entry->ufd = ufd; + ), + + TP_printk("prog=%s type=%s ufd=%d", + __print_hex_str(__entry->prog_tag, 8), + __print_symbolic(__entry->type, __PROG_TYPE_SYM_TAB), + __entry->ufd) +); + +TRACE_EVENT(bpf_map_create, + + TP_PROTO(const struct bpf_map *map, int ufd), + + TP_ARGS(map, ufd), + + TP_STRUCT__entry( + __field(u32, type) + __field(u32, size_key) + __field(u32, size_value) + __field(u32, max_entries) + __field(u32, flags) + __field(int, ufd) + ), + + TP_fast_assign( + __entry->type = map->map_type; + __entry->size_key = map->key_size; + __entry->size_value = map->value_size; + __entry->max_entries = map->max_entries; + __entry->flags = map->map_flags; + __entry->ufd = ufd; + ), + + TP_printk("map type=%s ufd=%d key=%u val=%u max=%u flags=%x", + __print_symbolic(__entry->type, __MAP_TYPE_SYM_TAB), + __entry->ufd, __entry->size_key, __entry->size_value, + __entry->max_entries, __entry->flags) +); + +DECLARE_EVENT_CLASS(bpf_obj_prog, + + TP_PROTO(const struct bpf_prog *prg, int ufd, + const struct filename *pname), + + TP_ARGS(prg, ufd, pname), + + TP_STRUCT__entry( + __array(u8, prog_tag, 8) + __field(int, ufd) + __string(path, pname->name) + ), + + TP_fast_assign( + BUILD_BUG_ON(sizeof(__entry->prog_tag) != sizeof(prg->tag)); + memcpy(__entry->prog_tag, prg->tag, sizeof(prg->tag)); + __assign_str(path, pname->name); + __entry->ufd = ufd; + ), + + TP_printk("prog=%s path=%s ufd=%d", + __print_hex_str(__entry->prog_tag, 8), + __get_str(path), __entry->ufd) +); + +DEFINE_EVENT(bpf_obj_prog, bpf_obj_pin_prog, + + TP_PROTO(const struct bpf_prog *prg, int ufd, + const struct filename *pname), + + TP_ARGS(prg, ufd, pname) +); + +DEFINE_EVENT(bpf_obj_prog, bpf_obj_get_prog, + + TP_PROTO(const struct bpf_prog *prg, int ufd, + const struct filename *pname), + + TP_ARGS(prg, ufd, pname) +); + +DECLARE_EVENT_CLASS(bpf_obj_map, + + TP_PROTO(const struct bpf_map *map, int ufd, + const struct filename *pname), + + TP_ARGS(map, ufd, pname), + + TP_STRUCT__entry( + __field(u32, type) + __field(int, ufd) + __string(path, pname->name) + ), + + TP_fast_assign( + __assign_str(path, pname->name); + __entry->type = map->map_type; + __entry->ufd = ufd; + ), + + TP_printk("map type=%s ufd=%d path=%s", + __print_symbolic(__entry->type, __MAP_TYPE_SYM_TAB), + __entry->ufd, __get_str(path)) +); + +DEFINE_EVENT(bpf_obj_map, bpf_obj_pin_map, + + TP_PROTO(const struct bpf_map *map, int ufd, + const struct filename *pname), + + TP_ARGS(map, ufd, pname) +); + +DEFINE_EVENT(bpf_obj_map, bpf_obj_get_map, + + TP_PROTO(const struct bpf_map *map, int ufd, + const struct filename *pname), + + TP_ARGS(map, ufd, pname) +); + +DECLARE_EVENT_CLASS(bpf_map_keyval, + + TP_PROTO(const struct bpf_map *map, int ufd, + const void *key, const void *val), + + TP_ARGS(map, ufd, key, val), + + TP_STRUCT__entry( + __field(u32, type) + __field(u32, key_len) + __dynamic_array(u8, key, map->key_size) + __field(bool, key_trunc) + __field(u32, val_len) + __dynamic_array(u8, val, map->value_size) + __field(bool, val_trunc) + __field(int, ufd) + ), + + TP_fast_assign( + memcpy(__get_dynamic_array(key), key, map->key_size); + memcpy(__get_dynamic_array(val), val, map->value_size); + __entry->type = map->map_type; + __entry->key_len = min(map->key_size, 16U); + __entry->key_trunc = map->key_size != __entry->key_len; + __entry->val_len = min(map->value_size, 16U); + __entry->val_trunc = map->value_size != __entry->val_len; + __entry->ufd = ufd; + ), + + TP_printk("map type=%s ufd=%d key=[%s%s] val=[%s%s]", + __print_symbolic(__entry->type, __MAP_TYPE_SYM_TAB), + __entry->ufd, + __print_hex(__get_dynamic_array(key), __entry->key_len), + __entry->key_trunc ? " ..." : "", + __print_hex(__get_dynamic_array(val), __entry->val_len), + __entry->val_trunc ? " ..." : "") +); + +DEFINE_EVENT(bpf_map_keyval, bpf_map_lookup_elem, + + TP_PROTO(const struct bpf_map *map, int ufd, + const void *key, const void *val), + + TP_ARGS(map, ufd, key, val) +); + +DEFINE_EVENT(bpf_map_keyval, bpf_map_update_elem, + + TP_PROTO(const struct bpf_map *map, int ufd, + const void *key, const void *val), + + TP_ARGS(map, ufd, key, val) +); + +TRACE_EVENT(bpf_map_delete_elem, + + TP_PROTO(const struct bpf_map *map, int ufd, + const void *key), + + TP_ARGS(map, ufd, key), + + TP_STRUCT__entry( + __field(u32, type) + __field(u32, key_len) + __dynamic_array(u8, key, map->key_size) + __field(bool, key_trunc) + __field(int, ufd) + ), + + TP_fast_assign( + memcpy(__get_dynamic_array(key), key, map->key_size); + __entry->type = map->map_type; + __entry->key_len = min(map->key_size, 16U); + __entry->key_trunc = map->key_size != __entry->key_len; + __entry->ufd = ufd; + ), + + TP_printk("map type=%s ufd=%d key=[%s%s]", + __print_symbolic(__entry->type, __MAP_TYPE_SYM_TAB), + __entry->ufd, + __print_hex(__get_dynamic_array(key), __entry->key_len), + __entry->key_trunc ? " ..." : "") +); + +TRACE_EVENT(bpf_map_next_key, + + TP_PROTO(const struct bpf_map *map, int ufd, + const void *key, const void *key_next), + + TP_ARGS(map, ufd, key, key_next), + + TP_STRUCT__entry( + __field(u32, type) + __field(u32, key_len) + __dynamic_array(u8, key, map->key_size) + __dynamic_array(u8, nxt, map->key_size) + __field(bool, key_trunc) + __field(int, ufd) + ), + + TP_fast_assign( + memcpy(__get_dynamic_array(key), key, map->key_size); + memcpy(__get_dynamic_array(nxt), key_next, map->key_size); + __entry->type = map->map_type; + __entry->key_len = min(map->key_size, 16U); + __entry->key_trunc = map->key_size != __entry->key_len; + __entry->ufd = ufd; + ), + + TP_printk("map type=%s ufd=%d key=[%s%s] next=[%s%s]", + __print_symbolic(__entry->type, __MAP_TYPE_SYM_TAB), + __entry->ufd, + __print_hex(__get_dynamic_array(key), __entry->key_len), + __entry->key_trunc ? " ..." : "", + __print_hex(__get_dynamic_array(nxt), __entry->key_len), + __entry->key_trunc ? " ..." : "") +); + +#endif /* _TRACE_BPF_H */ + +#include diff --git a/include/trace/events/xdp.h b/include/trace/events/xdp.h new file mode 100644 index 000000000000..1b61357d3f57 --- /dev/null +++ b/include/trace/events/xdp.h @@ -0,0 +1,53 @@ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM xdp + +#if !defined(_TRACE_XDP_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_XDP_H + +#include +#include +#include + +#define __XDP_ACT_MAP(FN) \ + FN(ABORTED) \ + FN(DROP) \ + FN(PASS) \ + FN(TX) + +#define __XDP_ACT_TP_FN(x) \ + TRACE_DEFINE_ENUM(XDP_##x); +#define __XDP_ACT_SYM_FN(x) \ + { XDP_##x, #x }, +#define __XDP_ACT_SYM_TAB \ + __XDP_ACT_MAP(__XDP_ACT_SYM_FN) { -1, 0 } +__XDP_ACT_MAP(__XDP_ACT_TP_FN) + +TRACE_EVENT(xdp_exception, + + TP_PROTO(const struct net_device *dev, + const struct bpf_prog *xdp, u32 act), + + TP_ARGS(dev, xdp, act), + + TP_STRUCT__entry( + __string(name, dev->name) + __array(u8, prog_tag, 8) + __field(u32, act) + ), + + TP_fast_assign( + BUILD_BUG_ON(sizeof(__entry->prog_tag) != sizeof(xdp->tag)); + memcpy(__entry->prog_tag, xdp->tag, sizeof(xdp->tag)); + __assign_str(name, dev->name); + __entry->act = act; + ), + + TP_printk("prog=%s device=%s action=%s", + __print_hex_str(__entry->prog_tag, 8), + __get_str(name), + __print_symbolic(__entry->act, __XDP_ACT_SYM_TAB)) +); + +#endif /* _TRACE_XDP_H */ + +#include diff --git a/kernel/bpf/core.c b/kernel/bpf/core.c index 503d4211988a..fddd76b1b627 100644 --- a/kernel/bpf/core.c +++ b/kernel/bpf/core.c @@ -1173,3 +1173,12 @@ int __weak skb_copy_bits(const struct sk_buff *skb, int offset, void *to, { return -EFAULT; } + +/* All definitions of tracepoints related to BPF. */ +#define CREATE_TRACE_POINTS +#include + +EXPORT_TRACEPOINT_SYMBOL_GPL(xdp_exception); + +EXPORT_TRACEPOINT_SYMBOL_GPL(bpf_prog_get_type); +EXPORT_TRACEPOINT_SYMBOL_GPL(bpf_prog_put_rcu); diff --git a/kernel/bpf/inode.c b/kernel/bpf/inode.c index 0b030c9126d3..fddcae801724 100644 --- a/kernel/bpf/inode.c +++ b/kernel/bpf/inode.c @@ -21,6 +21,7 @@ #include #include #include +#include enum bpf_type { BPF_TYPE_UNSPEC = 0, @@ -281,6 +282,13 @@ int bpf_obj_pin_user(u32 ufd, const char __user *pathname) ret = bpf_obj_do_pin(pname, raw, type); if (ret != 0) bpf_any_put(raw, type); + if ((trace_bpf_obj_pin_prog_enabled() || + trace_bpf_obj_pin_map_enabled()) && !ret) { + if (type == BPF_TYPE_PROG) + trace_bpf_obj_pin_prog(raw, ufd, pname); + if (type == BPF_TYPE_MAP) + trace_bpf_obj_pin_map(raw, ufd, pname); + } out: putname(pname); return ret; @@ -342,8 +350,15 @@ int bpf_obj_get_user(const char __user *pathname) else goto out; - if (ret < 0) + if (ret < 0) { bpf_any_put(raw, type); + } else if (trace_bpf_obj_get_prog_enabled() || + trace_bpf_obj_get_map_enabled()) { + if (type == BPF_TYPE_PROG) + trace_bpf_obj_get_prog(raw, ret, pname); + if (type == BPF_TYPE_MAP) + trace_bpf_obj_get_map(raw, ret, pname); + } out: putname(pname); return ret; diff --git a/kernel/bpf/syscall.c b/kernel/bpf/syscall.c index 1d6b29e4e2c3..05ad086ab71d 100644 --- a/kernel/bpf/syscall.c +++ b/kernel/bpf/syscall.c @@ -10,6 +10,7 @@ * General Public License for more details. */ #include +#include #include #include #include @@ -215,6 +216,7 @@ static int map_create(union bpf_attr *attr) /* failed to allocate fd */ goto free_map; + trace_bpf_map_create(map, err); return err; free_map: @@ -339,6 +341,7 @@ static int map_lookup_elem(union bpf_attr *attr) if (copy_to_user(uvalue, value, value_size) != 0) goto free_value; + trace_bpf_map_lookup_elem(map, ufd, key, value); err = 0; free_value: @@ -421,6 +424,8 @@ static int map_update_elem(union bpf_attr *attr) __this_cpu_dec(bpf_prog_active); preempt_enable(); + if (!err) + trace_bpf_map_update_elem(map, ufd, key, value); free_value: kfree(value); free_key: @@ -466,6 +471,8 @@ static int map_delete_elem(union bpf_attr *attr) __this_cpu_dec(bpf_prog_active); preempt_enable(); + if (!err) + trace_bpf_map_delete_elem(map, ufd, key); free_key: kfree(key); err_put: @@ -518,6 +525,7 @@ static int map_get_next_key(union bpf_attr *attr) if (copy_to_user(unext_key, next_key, map->key_size) != 0) goto free_next_key; + trace_bpf_map_next_key(map, ufd, key, next_key); err = 0; free_next_key: @@ -671,8 +679,10 @@ static void __bpf_prog_put_rcu(struct rcu_head *rcu) void bpf_prog_put(struct bpf_prog *prog) { - if (atomic_dec_and_test(&prog->aux->refcnt)) + if (atomic_dec_and_test(&prog->aux->refcnt)) { + trace_bpf_prog_put_rcu(prog); call_rcu(&prog->aux->rcu, __bpf_prog_put_rcu); + } } EXPORT_SYMBOL_GPL(bpf_prog_put); @@ -781,7 +791,11 @@ struct bpf_prog *bpf_prog_get(u32 ufd) struct bpf_prog *bpf_prog_get_type(u32 ufd, enum bpf_prog_type type) { - return __bpf_prog_get(ufd, &type); + struct bpf_prog *prog = __bpf_prog_get(ufd, &type); + + if (!IS_ERR(prog)) + trace_bpf_prog_get_type(prog); + return prog; } EXPORT_SYMBOL_GPL(bpf_prog_get_type); @@ -863,6 +877,7 @@ static int bpf_prog_load(union bpf_attr *attr) /* failed to allocate fd */ goto free_used_maps; + trace_bpf_prog_load(prog, err); return err; free_used_maps: -- cgit v1.2.3-55-g7522 From 3898fac1f488c76e0eef5b5267b4ba8112a82ac4 Mon Sep 17 00:00:00 2001 From: Daniel Borkmann Date: Thu, 2 Feb 2017 17:09:54 +0100 Subject: trace: rename trace_print_hex_seq arg and add kdoc Steven suggested to improve trace_print_hex_seq() a bit after commit 2acae0d5b0f7 ("trace: add variant without spacing in trace_print_hex_seq") in two ways: i) by adding a kdoc comment for the helper function itself and ii) by renaming 'spacing' argument into 'concatenate' to better denote that we don't add spaces between each hex bytes. Suggested-by: Steven Rostedt Signed-off-by: Daniel Borkmann Signed-off-by: David S. Miller --- include/linux/trace_events.h | 2 +- include/trace/trace_events.h | 4 ++-- kernel/trace/trace_output.c | 15 +++++++++++++-- 3 files changed, 16 insertions(+), 5 deletions(-) (limited to 'include/trace') diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h index cfa475a0e9ca..0f165507495c 100644 --- a/include/linux/trace_events.h +++ b/include/linux/trace_events.h @@ -34,7 +34,7 @@ const char *trace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr, const char *trace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int len, - bool spacing); + bool concatenate); const char *trace_print_array_seq(struct trace_seq *p, const void *buf, int count, diff --git a/include/trace/trace_events.h b/include/trace/trace_events.h index 9f684629c3cf..5c06f4af8323 100644 --- a/include/trace/trace_events.h +++ b/include/trace/trace_events.h @@ -298,11 +298,11 @@ TRACE_MAKE_SYSTEM_STR(); #undef __print_hex #define __print_hex(buf, buf_len) \ - trace_print_hex_seq(p, buf, buf_len, true) + trace_print_hex_seq(p, buf, buf_len, false) #undef __print_hex_str #define __print_hex_str(buf, buf_len) \ - trace_print_hex_seq(p, buf, buf_len, false) + trace_print_hex_seq(p, buf, buf_len, true) #undef __print_array #define __print_array(array, count, el_size) \ diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c index 30a144b1b9ee..aea6a1218c7d 100644 --- a/kernel/trace/trace_output.c +++ b/kernel/trace/trace_output.c @@ -162,15 +162,26 @@ trace_print_bitmask_seq(struct trace_seq *p, void *bitmask_ptr, } EXPORT_SYMBOL_GPL(trace_print_bitmask_seq); +/** + * trace_print_hex_seq - print buffer as hex sequence + * @p: trace seq struct to write to + * @buf: The buffer to print + * @buf_len: Length of @buf in bytes + * @concatenate: Print @buf as single hex string or with spacing + * + * Prints the passed buffer as a hex sequence either as a whole, + * single hex string if @concatenate is true or with spacing after + * each byte in case @concatenate is false. + */ const char * trace_print_hex_seq(struct trace_seq *p, const unsigned char *buf, int buf_len, - bool spacing) + bool concatenate) { int i; const char *ret = trace_seq_buffer_ptr(p); for (i = 0; i < buf_len; i++) - trace_seq_printf(p, "%s%2.2x", !spacing || i == 0 ? "" : " ", + trace_seq_printf(p, "%s%2.2x", concatenate || i == 0 ? "" : " ", buf[i]); trace_seq_putc(p, 0); -- cgit v1.2.3-55-g7522