diff --git a/include/zephyr/tracing/tracing.h b/include/zephyr/tracing/tracing.h index 35c818f5a35e..e969c4eec5cd 100644 --- a/include/zephyr/tracing/tracing.h +++ b/include/zephyr/tracing/tracing.h @@ -2069,6 +2069,13 @@ */ #define sys_port_trace_net_rx_time(pkt, end_time) +/** + * @brief Trace network data sent time + * @param pkt Sent network packet + * @param end_time When the TX processing stopped for this pkt (in ticks) + */ +#define sys_port_trace_net_tx_time(pkt, end_time) + /** @} */ /* end of subsys_tracing_apis_net */ /** diff --git a/subsys/net/ip/net_if.c b/subsys/net/ip/net_if.c index 98d71319d24c..52bee86de8ac 100644 --- a/subsys/net/ip/net_if.c +++ b/subsys/net/ip/net_if.c @@ -247,7 +247,8 @@ static bool net_if_tx(struct net_if *iface, struct net_pkt *pkt) context = net_pkt_context(pkt); if (net_if_flag_is_set(iface, NET_IF_LOWER_UP)) { - if (IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS)) { + if (IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS) || + IS_ENABLED(CONFIG_TRACING_NET_CORE)) { pkt_priority = net_pkt_priority(pkt); if (IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS_DETAIL)) { @@ -262,7 +263,8 @@ static bool net_if_tx(struct net_if *iface, struct net_pkt *pkt) status = net_if_l2(iface)->send(iface, pkt); net_if_tx_unlock(iface); - if (IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS)) { + if (IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS) || + IS_ENABLED(CONFIG_TRACING_NET_CORE)) { uint32_t end_tick = k_cycle_get_32(); net_pkt_set_tx_stats_tick(pkt, end_tick); @@ -272,6 +274,8 @@ static bool net_if_tx(struct net_if *iface, struct net_pkt *pkt) create_time, end_tick); + SYS_PORT_TRACING_FUNC(net, tx_time, pkt, end_tick); + if (IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS_DETAIL)) { update_txtime_stats_detail( pkt, diff --git a/subsys/net/ip/net_pkt.c b/subsys/net/ip/net_pkt.c index d0ee06487d6d..83e92305a198 100644 --- a/subsys/net/ip/net_pkt.c +++ b/subsys/net/ip/net_pkt.c @@ -1274,7 +1274,8 @@ static struct net_pkt *pkt_alloc(struct k_mem_slab *slab, k_timeout_t timeout) } if (IS_ENABLED(CONFIG_NET_PKT_RXTIME_STATS) || - IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS)) { + IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS) || + IS_ENABLED(CONFIG_TRACING_NET_CORE)) { create_time = k_cycle_get_32(); } else { ARG_UNUSED(create_time); @@ -1313,7 +1314,8 @@ static struct net_pkt *pkt_alloc(struct k_mem_slab *slab, k_timeout_t timeout) } if (IS_ENABLED(CONFIG_NET_PKT_RXTIME_STATS) || - IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS)) { + IS_ENABLED(CONFIG_NET_PKT_TXTIME_STATS) || + IS_ENABLED(CONFIG_TRACING_NET_CORE)) { net_pkt_set_create_time(pkt, create_time); } diff --git a/subsys/net/lib/sockets/sockets_packet.c b/subsys/net/lib/sockets/sockets_packet.c index 6a793fcdac1d..3fe9258c7996 100644 --- a/subsys/net/lib/sockets/sockets_packet.c +++ b/subsys/net/lib/sockets/sockets_packet.c @@ -345,7 +345,8 @@ ssize_t zpacket_recvfrom_ctx(struct net_context *ctx, void *buf, size_t max_len, zpacket_set_source_addr(ctx, pkt, src_addr, addrlen); } - if (IS_ENABLED(CONFIG_NET_PKT_RXTIME_STATS) && + if ((IS_ENABLED(CONFIG_NET_PKT_RXTIME_STATS) || + IS_ENABLED(CONFIG_TRACING_NET_CORE)) && !(flags & ZSOCK_MSG_PEEK)) { net_socket_update_tc_rx_time(pkt, k_cycle_get_32()); } diff --git a/subsys/tracing/ctf/ctf_top.c b/subsys/tracing/ctf/ctf_top.c index 2eaa327f20bc..12ab43709f3e 100644 --- a/subsys/tracing/ctf/ctf_top.c +++ b/subsys/tracing/ctf/ctf_top.c @@ -718,3 +718,31 @@ void sys_trace_net_rx_time(struct net_pkt *pkt, uint32_t end_time) (uint32_t)tc, (uint32_t)duration_us); } + +void sys_trace_net_tx_time(struct net_pkt *pkt, uint32_t end_time) +{ + struct net_if *iface; + int ifindex; + uint32_t diff; + int tc; + uint32_t duration_us; + + iface = net_pkt_iface(pkt); + if (iface == NULL) { + ifindex = -1; + tc = 0; + duration_us = 0; + } else { + ifindex = net_if_get_by_iface(iface); + diff = end_time - net_pkt_create_time(pkt); + tc = net_rx_priority2tc(net_pkt_priority(pkt)); + duration_us = k_cyc_to_ns_floor64(diff) / 1000U; + } + + ctf_top_net_tx_time((int32_t)ifindex, + (uint32_t)(uintptr_t)iface, + (uint32_t)(uintptr_t)pkt, + (uint32_t)net_pkt_priority(pkt), + (uint32_t)tc, + (uint32_t)duration_us); +} diff --git a/subsys/tracing/ctf/ctf_top.h b/subsys/tracing/ctf/ctf_top.h index d250ac2f1ecb..4929107bfddb 100644 --- a/subsys/tracing/ctf/ctf_top.h +++ b/subsys/tracing/ctf/ctf_top.h @@ -156,6 +156,7 @@ typedef enum { CTF_EVENT_NET_SEND_DATA_ENTER = 0x5E, CTF_EVENT_NET_SEND_DATA_EXIT = 0x5F, CTF_EVENT_NET_RX_TIME = 0x60, + CTF_EVENT_NET_TX_TIME = 0x61, } ctf_event_t; @@ -650,4 +651,11 @@ static inline void ctf_top_net_rx_time(int32_t if_index, uint32_t iface, uint32_ if_index, iface, pkt, priority, tc, duration); } +static inline void ctf_top_net_tx_time(int32_t if_index, uint32_t iface, uint32_t pkt, + uint32_t priority, uint32_t tc, uint32_t duration) +{ + CTF_EVENT(CTF_LITERAL(uint8_t, CTF_EVENT_NET_TX_TIME), + if_index, iface, pkt, priority, tc, duration); +} + #endif /* SUBSYS_DEBUG_TRACING_CTF_TOP_H */ diff --git a/subsys/tracing/ctf/tracing_ctf.h b/subsys/tracing/ctf/tracing_ctf.h index 95a26654bf32..ab87411c9119 100644 --- a/subsys/tracing/ctf/tracing_ctf.h +++ b/subsys/tracing/ctf/tracing_ctf.h @@ -579,6 +579,8 @@ void sys_trace_socket_socketpair_exit(int sock_A, int sock_B, int ret); sys_trace_net_send_data_exit(pkt, ret) #define sys_port_trace_net_rx_time(pkt, end_time) \ sys_trace_net_rx_time(pkt, end_time) +#define sys_port_trace_net_tx_time(pkt, end_time) \ + sys_trace_net_tx_time(pkt, end_time) struct net_if; struct net_pkt; @@ -588,6 +590,7 @@ void sys_trace_net_recv_data_exit(struct net_if *iface, struct net_pkt *pkt, int void sys_trace_net_send_data_enter(struct net_pkt *pkt); void sys_trace_net_send_data_exit(struct net_pkt *pkt, int ret); void sys_trace_net_rx_time(struct net_pkt *pkt, uint32_t end_time); +void sys_trace_net_tx_time(struct net_pkt *pkt, uint32_t end_time); #ifdef __cplusplus } diff --git a/subsys/tracing/ctf/tsdl/metadata b/subsys/tracing/ctf/tsdl/metadata index a4c86e895d68..efaa2adc0922 100644 --- a/subsys/tracing/ctf/tsdl/metadata +++ b/subsys/tracing/ctf/tsdl/metadata @@ -764,3 +764,16 @@ event { uint32_t duration_us; }; }; + +event { + name = net_tx_time; + id = 0x61; + fields := struct { + int32_t if_index; + uint32_t iface; + uint32_t pkt; + uint32_t priority; + uint32_t traffic_class; + uint32_t duration_us; + }; +}; diff --git a/subsys/tracing/test/tracing_test.h b/subsys/tracing/test/tracing_test.h index b024b8f5ac67..3afbb7940366 100644 --- a/subsys/tracing/test/tracing_test.h +++ b/subsys/tracing/test/tracing_test.h @@ -737,6 +737,7 @@ void sys_trace_k_event_init(struct k_event *event); #define sys_port_trace_net_send_data_enter(pkt) #define sys_port_trace_net_send_data_exit(pkt, ret) #define sys_port_trace_net_rx_time(pkt, end_time) +#define sys_port_trace_net_tx_time(pkt, end_time) #define sys_trace_sys_init_enter(...) #define sys_trace_sys_init_exit(...) diff --git a/subsys/tracing/user/tracing_user.h b/subsys/tracing/user/tracing_user.h index 0f2c5415d15f..8d6630895316 100644 --- a/subsys/tracing/user/tracing_user.h +++ b/subsys/tracing/user/tracing_user.h @@ -388,6 +388,7 @@ void sys_trace_sys_init_exit(const struct init_entry *entry, int level, int resu #define sys_port_trace_net_send_data_enter(pkt) #define sys_port_trace_net_send_data_exit(pkt, ret) #define sys_port_trace_net_rx_time(pkt, end_time) +#define sys_port_trace_net_tx_time(pkt, end_time) #ifdef __cplusplus }