Here's my naive first pass. Tested with a modified libtraceevent.
nfsd-1006 [000] 615.380178: nfsd_cb_args: addr=192.168.2.67:38673 client 61ddcfcf:54b96b71 prog=1073741824 ident=1
nfsd-1006 [000] 615.380242: nfsd_cb_probe: addr=192.168.2.67:38673 client 61ddcfcf:54b96b71 state=UNKNOWN
kworker/u8:5-79 [002] 615.380307: nfsd_cb_setup: addr=192.168.2.67:38673 client 61ddcfcf:54b96b71 proto=tcp flavor=sys
kworker/u8:4-78 [001] 615.380459: nfsd_cb_state: addr=192.168.2.67:38673 client 61ddcfcf:54b96b71 state=UP
nfsd-1006 [000] 615.380599: nfsd_cb_args: addr=192.168.2.67:38673 client 61ddcfcf:54b96b71 prog=1073741824 ident=1
nfsd-1006 [000] 615.380661: nfsd_cb_state: addr=192.168.2.67:38673 client 61ddcfcf:54b96b71 state=UNKNOWN
nfsd-1006 [000] 615.380661: nfsd_cb_probe: addr=192.168.2.67:38673 client 61ddcfcf:54b96b71 state=UNKNOWN
kworker/u8:4-78 [000] 615.380715: nfsd_cb_setup: addr=192.168.2.67:38673 client 61ddcfcf:54b96b71 proto=tcp flavor=sys
kworker/u8:4-78 [000] 615.380865: nfsd_cb_state: addr=192.168.2.67:38673 client 61ddcfcf:54b96b71 state=UP
And in the raw:
nfsd-1006 [000] 615.380178: nfsd_cb_args: cl_boot=61ddcfcf cl_id=54b96b71 prog=1073741824 ident=1 addr=ARRAY[02, 00, 97, 11, c0, a8, 02, 43, 00, 00, 00, 00, 00, 00, 00, 00]
nfsd-1006 [000] 615.380242: nfsd_cb_probe: state=0x1 cl_boot=61ddcfcf cl_id=54b96b71 addr=ARRAY[02, 00, 97, 11, c0, a8, 02, 43, 00, 00, 00, 00, 00, 00, 00, 00]
kworker/u8:5-79 [002] 615.380307: nfsd_cb_setup: cl_boot=61ddcfcf cl_id=54b96b71 authflavor=0x1 addr=ARRAY[02, 00, 97, 11, c0, a8, 02, 43, 00, 00, 00, 00, 00, 00, 00, 00] netid=tcp
kworker/u8:4-78 [001] 615.380459: nfsd_cb_state: state=0x0 cl_boot=61ddcfcf cl_id=54b96b71 addr=ARRAY[02, 00, 97, 11, c0, a8, 02, 43, 00, 00, 00, 00, 00, 00, 00, 00]
nfsd-1006 [000] 615.380599: nfsd_cb_args: cl_boot=61ddcfcf cl_id=54b96b71 prog=1073741824 ident=1 addr=ARRAY[02, 00, 97, 11, c0, a8, 02, 43, 00, 00, 00, 00, 00, 00, 00, 00]
nfsd-1006 [000] 615.380661: nfsd_cb_state: state=0x1 cl_boot=61ddcfcf cl_id=54b96b71 addr=ARRAY[02, 00, 97, 11, c0, a8, 02, 43, 00, 00, 00, 00, 00, 00, 00, 00]
nfsd-1006 [000] 615.380661: nfsd_cb_probe: state=0x1 cl_boot=61ddcfcf cl_id=54b96b71 addr=ARRAY[02, 00, 97, 11, c0, a8, 02, 43, 00, 00, 00, 00, 00, 00, 00, 00]
kworker/u8:4-78 [000] 615.380715: nfsd_cb_setup: cl_boot=61ddcfcf cl_id=54b96b71 authflavor=0x1 addr=ARRAY[02, 00, 97, 11, c0, a8, 02, 43, 00, 00, 00, 00, 00, 00, 00, 00] netid=tcp
kworker/u8:4-78 [000] 615.380865: nfsd_cb_state: state=0x0 cl_boot=61ddcfcf cl_id=54b96b71 addr=ARRAY[02, 00, 97, 11, c0, a8, 02, 43, 00, 00, 00, 00, 00, 00, 00, 00]
Comments welcome.
---
Chuck Lever (2):
trace: Introduce helpers to safely handle dynamic-sized sockaddrs
NFSD: Use __sockaddr field to store socket addresses
fs/nfsd/trace.h | 79 ++++++++++++++++++------------------
include/trace/bpf_probe.h | 3 ++
include/trace/perf.h | 3 ++
include/trace/trace_events.h | 18 ++++++++
4 files changed, 63 insertions(+), 40 deletions(-)
--
Chuck Lever
Enable a struct sockaddr to be stored in a trace record as a
dynamically-sized field. The common cases are AF_INET and AF_INET6
which are different sizes, and are vastly smaller than a struct
sockaddr_storage.
These are safer because, when used properly, the size of the
sockaddr destination field in each trace record is now guaranteed
to be the same as the source address that is being copied into it.
Link: https://lore.kernel.org/all/164182978641.8391.8277203495236105391.stgit@bazille.1015granger.net/
Signed-off-by: Chuck Lever <[email protected]>
---
include/trace/bpf_probe.h | 3 +++
include/trace/perf.h | 3 +++
include/trace/trace_events.h | 18 ++++++++++++++++++
3 files changed, 24 insertions(+)
diff --git a/include/trace/bpf_probe.h b/include/trace/bpf_probe.h
index a8e97f84b652..74068d7b3103 100644
--- a/include/trace/bpf_probe.h
+++ b/include/trace/bpf_probe.h
@@ -21,6 +21,9 @@
#undef __get_bitmask
#define __get_bitmask(field) (char *)__get_dynamic_array(field)
+#undef __get_sockaddr
+#define __get_sockaddr(field) ((struct sockaddr *)__get_dynamic_array(field))
+
#undef __perf_count
#define __perf_count(c) (c)
diff --git a/include/trace/perf.h b/include/trace/perf.h
index dbc6c74defc3..953ff4a25691 100644
--- a/include/trace/perf.h
+++ b/include/trace/perf.h
@@ -21,6 +21,9 @@
#undef __get_bitmask
#define __get_bitmask(field) (char *)__get_dynamic_array(field)
+#undef __get_sockaddr
+#define __get_sockaddr(field) ((struct sockaddr *)__get_dynamic_array(field))
+
#undef __perf_count
#define __perf_count(c) (__count = (c))
diff --git a/include/trace/trace_events.h b/include/trace/trace_events.h
index 08810a463880..003104159087 100644
--- a/include/trace/trace_events.h
+++ b/include/trace/trace_events.h
@@ -108,6 +108,9 @@ TRACE_MAKE_SYSTEM_STR();
#undef __bitmask
#define __bitmask(item, nr_bits) __dynamic_array(char, item, -1)
+#undef __sockaddr
+#define __sockaddr(field, len) __dynamic_array(u8, field, len)
+
#undef TP_STRUCT__entry
#define TP_STRUCT__entry(args...) args
@@ -206,6 +209,9 @@ TRACE_MAKE_SYSTEM_STR();
#undef __bitmask
#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1)
+#undef __sockaddr
+#define __sockaddr(field, len) __dynamic_array(u8, field, len)
+
#undef DECLARE_EVENT_CLASS
#define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print) \
struct trace_event_data_offsets_##call { \
@@ -302,6 +308,9 @@ TRACE_MAKE_SYSTEM_STR();
trace_print_bitmask_seq(p, __bitmask, __bitmask_size); \
})
+#undef __get_sockaddr
+#define __get_sockaddr(field) ((struct sockaddr *)__get_dynamic_array(field))
+
#undef __print_flags
#define __print_flags(flag, delim, flag_array...) \
({ \
@@ -471,6 +480,9 @@ static struct trace_event_functions trace_event_type_funcs_##call = { \
#undef __bitmask
#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, -1)
+#undef __sockaddr
+#define __sockaddr(field, len) __dynamic_array(u8, field, len)
+
#undef DECLARE_EVENT_CLASS
#define DECLARE_EVENT_CLASS(call, proto, args, tstruct, func, print) \
static struct trace_event_fields trace_event_fields_##call[] = { \
@@ -542,6 +554,9 @@ static struct trace_event_fields trace_event_fields_##call[] = { \
#define __bitmask(item, nr_bits) __dynamic_array(unsigned long, item, \
__bitmask_size_in_longs(nr_bits))
+#undef __sockaddr
+#define __sockaddr(field, len) __dynamic_array(u8, field, len)
+
#undef DECLARE_EVENT_CLASS
#define DECLARE_EVENT_CLASS(call, proto, args, tstruct, assign, print) \
static inline notrace int trace_event_get_offsets_##call( \
@@ -706,6 +721,9 @@ static inline notrace int trace_event_get_offsets_##call( \
#define __assign_bitmask(dst, src, nr_bits) \
memcpy(__get_bitmask(dst), (src), __bitmask_size_in_bytes(nr_bits))
+#define __assign_sockaddr(dest, src, len) \
+ memcpy(__get_dynamic_array(dest), src, len)
+
#undef TP_fast_assign
#define TP_fast_assign(args...) args
As an example usage of the new __sockaddr field, convert some NFSD
trace points to use it.
Signed-off-by: Chuck Lever <[email protected]>
---
fs/nfsd/trace.h | 79 +++++++++++++++++++++++++++----------------------------
1 file changed, 39 insertions(+), 40 deletions(-)
diff --git a/fs/nfsd/trace.h b/fs/nfsd/trace.h
index f1e0d3c51bc2..1ade489458fc 100644
--- a/fs/nfsd/trace.h
+++ b/fs/nfsd/trace.h
@@ -549,20 +549,21 @@ TRACE_EVENT(nfsd_clid_cred_mismatch,
__field(u32, cl_id)
__field(unsigned long, cl_flavor)
__field(unsigned long, new_flavor)
- __array(unsigned char, addr, sizeof(struct sockaddr_in6))
+ __sockaddr(addr, rqstp->rq_xprt->xpt_remotelen)
),
TP_fast_assign(
__entry->cl_boot = clp->cl_clientid.cl_boot;
__entry->cl_id = clp->cl_clientid.cl_id;
__entry->cl_flavor = clp->cl_cred.cr_flavor;
__entry->new_flavor = rqstp->rq_cred.cr_flavor;
- memcpy(__entry->addr, &rqstp->rq_xprt->xpt_remote,
- sizeof(struct sockaddr_in6));
+ __assign_sockaddr(addr, &rqstp->rq_xprt->xpt_remote,
+ rqstp->rq_xprt->xpt_remotelen);
),
TP_printk("client %08x:%08x flavor=%s, conflict=%s from addr=%pISpc",
__entry->cl_boot, __entry->cl_id,
show_nfsd_authflavor(__entry->cl_flavor),
- show_nfsd_authflavor(__entry->new_flavor), __entry->addr
+ show_nfsd_authflavor(__entry->new_flavor),
+ __get_sockaddr(addr)
)
)
@@ -578,7 +579,7 @@ TRACE_EVENT(nfsd_clid_verf_mismatch,
__field(u32, cl_id)
__array(unsigned char, cl_verifier, NFS4_VERIFIER_SIZE)
__array(unsigned char, new_verifier, NFS4_VERIFIER_SIZE)
- __array(unsigned char, addr, sizeof(struct sockaddr_in6))
+ __sockaddr(addr, rqstp->rq_xprt->xpt_remotelen)
),
TP_fast_assign(
__entry->cl_boot = clp->cl_clientid.cl_boot;
@@ -587,14 +588,14 @@ TRACE_EVENT(nfsd_clid_verf_mismatch,
NFS4_VERIFIER_SIZE);
memcpy(__entry->new_verifier, (void *)verf,
NFS4_VERIFIER_SIZE);
- memcpy(__entry->addr, &rqstp->rq_xprt->xpt_remote,
- sizeof(struct sockaddr_in6));
+ __assign_sockaddr(addr, &rqstp->rq_xprt->xpt_remote,
+ rqstp->rq_xprt->xpt_remotelen);
),
TP_printk("client %08x:%08x verf=0x%s, updated=0x%s from addr=%pISpc",
__entry->cl_boot, __entry->cl_id,
__print_hex_str(__entry->cl_verifier, NFS4_VERIFIER_SIZE),
__print_hex_str(__entry->new_verifier, NFS4_VERIFIER_SIZE),
- __entry->addr
+ __get_sockaddr(addr)
)
);
@@ -844,18 +845,17 @@ TRACE_EVENT(nfsd_cb_args,
__field(u32, cl_id)
__field(u32, prog)
__field(u32, ident)
- __array(unsigned char, addr, sizeof(struct sockaddr_in6))
+ __sockaddr(addr, conn->cb_addrlen)
),
TP_fast_assign(
__entry->cl_boot = clp->cl_clientid.cl_boot;
__entry->cl_id = clp->cl_clientid.cl_id;
__entry->prog = conn->cb_prog;
__entry->ident = conn->cb_ident;
- memcpy(__entry->addr, &conn->cb_addr,
- sizeof(struct sockaddr_in6));
+ __assign_sockaddr(addr, &conn->cb_addr, conn->cb_addrlen);
),
TP_printk("addr=%pISpc client %08x:%08x prog=%u ident=%u",
- __entry->addr, __entry->cl_boot, __entry->cl_id,
+ __get_sockaddr(addr), __entry->cl_boot, __entry->cl_id,
__entry->prog, __entry->ident)
);
@@ -887,17 +887,17 @@ DECLARE_EVENT_CLASS(nfsd_cb_class,
__field(unsigned long, state)
__field(u32, cl_boot)
__field(u32, cl_id)
- __array(unsigned char, addr, sizeof(struct sockaddr_in6))
+ __sockaddr(addr, clp->cl_cb_conn.cb_addrlen)
),
TP_fast_assign(
__entry->state = clp->cl_cb_state;
__entry->cl_boot = clp->cl_clientid.cl_boot;
__entry->cl_id = clp->cl_clientid.cl_id;
- memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
- sizeof(struct sockaddr_in6));
+ __assign_sockaddr(addr, &clp->cl_cb_conn.cb_addr,
+ clp->cl_cb_conn.cb_addrlen)
),
TP_printk("addr=%pISpc client %08x:%08x state=%s",
- __entry->addr, __entry->cl_boot, __entry->cl_id,
+ __get_sockaddr(addr), __entry->cl_boot, __entry->cl_id,
show_cb_state(__entry->state))
);
@@ -937,7 +937,7 @@ TRACE_EVENT(nfsd_cb_setup,
__field(u32, cl_boot)
__field(u32, cl_id)
__field(unsigned long, authflavor)
- __array(unsigned char, addr, sizeof(struct sockaddr_in6))
+ __sockaddr(addr, clp->cl_cb_conn.cb_addrlen)
__array(unsigned char, netid, 8)
),
TP_fast_assign(
@@ -945,11 +945,11 @@ TRACE_EVENT(nfsd_cb_setup,
__entry->cl_id = clp->cl_clientid.cl_id;
strlcpy(__entry->netid, netid, sizeof(__entry->netid));
__entry->authflavor = authflavor;
- memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
- sizeof(struct sockaddr_in6));
+ __assign_sockaddr(addr, &clp->cl_cb_conn.cb_addr,
+ clp->cl_cb_conn.cb_addrlen)
),
TP_printk("addr=%pISpc client %08x:%08x proto=%s flavor=%s",
- __entry->addr, __entry->cl_boot, __entry->cl_id,
+ __get_sockaddr(addr), __entry->cl_boot, __entry->cl_id,
__entry->netid, show_nfsd_authflavor(__entry->authflavor))
);
@@ -963,30 +963,32 @@ TRACE_EVENT(nfsd_cb_setup_err,
__field(long, error)
__field(u32, cl_boot)
__field(u32, cl_id)
- __array(unsigned char, addr, sizeof(struct sockaddr_in6))
+ __sockaddr(addr, clp->cl_cb_conn.cb_addrlen)
),
TP_fast_assign(
__entry->error = error;
__entry->cl_boot = clp->cl_clientid.cl_boot;
__entry->cl_id = clp->cl_clientid.cl_id;
- memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
- sizeof(struct sockaddr_in6));
+ __assign_sockaddr(addr, &clp->cl_cb_conn.cb_addr,
+ clp->cl_cb_conn.cb_addrlen)
),
TP_printk("addr=%pISpc client %08x:%08x error=%ld",
- __entry->addr, __entry->cl_boot, __entry->cl_id, __entry->error)
+ __get_sockaddr(addr), __entry->cl_boot, __entry->cl_id,
+ __entry->error)
);
-TRACE_EVENT(nfsd_cb_recall,
+TRACE_EVENT_CONDITION(nfsd_cb_recall,
TP_PROTO(
const struct nfs4_stid *stid
),
TP_ARGS(stid),
+ TP_CONDITION(stid->sc_client),
TP_STRUCT__entry(
__field(u32, cl_boot)
__field(u32, cl_id)
__field(u32, si_id)
__field(u32, si_generation)
- __array(unsigned char, addr, sizeof(struct sockaddr_in6))
+ __sockaddr(addr, stid->sc_client->cl_cb_conn.cb_addrlen)
),
TP_fast_assign(
const stateid_t *stp = &stid->sc_stateid;
@@ -996,14 +998,11 @@ TRACE_EVENT(nfsd_cb_recall,
__entry->cl_id = stp->si_opaque.so_clid.cl_id;
__entry->si_id = stp->si_opaque.so_id;
__entry->si_generation = stp->si_generation;
- if (clp)
- memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
- sizeof(struct sockaddr_in6));
- else
- memset(__entry->addr, 0, sizeof(struct sockaddr_in6));
+ __assign_sockaddr(addr, &clp->cl_cb_conn.cb_addr,
+ clp->cl_cb_conn.cb_addrlen)
),
TP_printk("addr=%pISpc client %08x:%08x stateid %08x:%08x",
- __entry->addr, __entry->cl_boot, __entry->cl_id,
+ __get_sockaddr(addr), __entry->cl_boot, __entry->cl_id,
__entry->si_id, __entry->si_generation)
);
@@ -1017,7 +1016,7 @@ TRACE_EVENT(nfsd_cb_notify_lock,
__field(u32, cl_boot)
__field(u32, cl_id)
__field(u32, fh_hash)
- __array(unsigned char, addr, sizeof(struct sockaddr_in6))
+ __sockaddr(addr, lo->lo_owner.so_client->cl_cb_conn.cb_addrlen)
),
TP_fast_assign(
const struct nfs4_client *clp = lo->lo_owner.so_client;
@@ -1025,11 +1024,11 @@ TRACE_EVENT(nfsd_cb_notify_lock,
__entry->cl_boot = clp->cl_clientid.cl_boot;
__entry->cl_id = clp->cl_clientid.cl_id;
__entry->fh_hash = knfsd_fh_hash(&nbl->nbl_fh);
- memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
- sizeof(struct sockaddr_in6));
+ __assign_sockaddr(addr, &clp->cl_cb_conn.cb_addr,
+ clp->cl_cb_conn.cb_addrlen)
),
TP_printk("addr=%pISpc client %08x:%08x fh_hash=0x%08x",
- __entry->addr, __entry->cl_boot, __entry->cl_id,
+ __get_sockaddr(addr), __entry->cl_boot, __entry->cl_id,
__entry->fh_hash)
);
@@ -1050,7 +1049,7 @@ TRACE_EVENT(nfsd_cb_offload,
__field(u32, fh_hash)
__field(int, status)
__field(u64, count)
- __array(unsigned char, addr, sizeof(struct sockaddr_in6))
+ __sockaddr(addr, clp->cl_cb_conn.cb_addrlen)
),
TP_fast_assign(
__entry->cl_boot = stp->si_opaque.so_clid.cl_boot;
@@ -1060,11 +1059,11 @@ TRACE_EVENT(nfsd_cb_offload,
__entry->fh_hash = knfsd_fh_hash(fh);
__entry->status = be32_to_cpu(status);
__entry->count = count;
- memcpy(__entry->addr, &clp->cl_cb_conn.cb_addr,
- sizeof(struct sockaddr_in6));
+ __assign_sockaddr(addr, &clp->cl_cb_conn.cb_addr,
+ clp->cl_cb_conn.cb_addrlen)
),
TP_printk("addr=%pISpc client %08x:%08x stateid %08x:%08x fh_hash=0x%08x count=%llu status=%d",
- __entry->addr, __entry->cl_boot, __entry->cl_id,
+ __get_sockaddr(addr), __entry->cl_boot, __entry->cl_id,
__entry->si_id, __entry->si_generation,
__entry->fh_hash, __entry->count, __entry->status)
);
On Tue, 11 Jan 2022 13:59:27 -0500
Chuck Lever <[email protected]> wrote:
> Enable a struct sockaddr to be stored in a trace record as a
> dynamically-sized field. The common cases are AF_INET and AF_INET6
> which are different sizes, and are vastly smaller than a struct
> sockaddr_storage.
>
> These are safer because, when used properly, the size of the
> sockaddr destination field in each trace record is now guaranteed
> to be the same as the source address that is being copied into it.
>
> Link: https://lore.kernel.org/all/164182978641.8391.8277203495236105391.stgit@bazille.1015granger.net/
> Signed-off-by: Chuck Lever <[email protected]>
> ---
This looks fine to me. The only comment I have is that the subject should
be "tracing: ..." not "trace: ..." as "tracing" is what we use for the
tracing subsystem.
I'll test this out if I get time.
-- Steve
> On Jan 13, 2022, at 12:24 PM, Steven Rostedt <[email protected]> wrote:
>
> On Tue, 11 Jan 2022 13:59:27 -0500
> Chuck Lever <[email protected]> wrote:
>
>> Enable a struct sockaddr to be stored in a trace record as a
>> dynamically-sized field. The common cases are AF_INET and AF_INET6
>> which are different sizes, and are vastly smaller than a struct
>> sockaddr_storage.
>>
>> These are safer because, when used properly, the size of the
>> sockaddr destination field in each trace record is now guaranteed
>> to be the same as the source address that is being copied into it.
>>
>> Link: https://lore.kernel.org/all/164182978641.8391.8277203495236105391.stgit@bazille.1015granger.net/
>> Signed-off-by: Chuck Lever <[email protected]>
>> ---
>
> This looks fine to me. The only comment I have is that the subject should
> be "tracing: ..." not "trace: ..." as "tracing" is what we use for the
> tracing subsystem.
Will fix.
> I'll test this out if I get time.
No hurry on my part.
--
Chuck Lever