Skip to content

Commit 10b9d99

Browse files
committed
SUNRPC: Augment server-side rpcgss tracepoints
Add similar tracepoints to those that were recently added on the client side to track failures in the integ and priv unwrap paths. And, let's collect the seqno-specific tracepoints together with a common naming convention. Regarding the gss_check_seq_num() changes: everywhere else treats the GSS sequence number as an unsigned 32-bit integer. As far back as 2.6.12, I couldn't find a compelling reason to do things differently here. As a defensive change it's better to eliminate needless implicit sign conversions. Signed-off-by: Chuck Lever <[email protected]>
1 parent 0e885e8 commit 10b9d99

File tree

3 files changed

+224
-64
lines changed

3 files changed

+224
-64
lines changed

include/trace/events/rpcgss.h

Lines changed: 142 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -170,55 +170,144 @@ DECLARE_EVENT_CLASS(rpcgss_ctx_class,
170170
DEFINE_CTX_EVENT(init);
171171
DEFINE_CTX_EVENT(destroy);
172172

173+
DECLARE_EVENT_CLASS(rpcgss_svc_gssapi_class,
174+
TP_PROTO(
175+
const struct svc_rqst *rqstp,
176+
u32 maj_stat
177+
),
178+
179+
TP_ARGS(rqstp, maj_stat),
180+
181+
TP_STRUCT__entry(
182+
__field(u32, xid)
183+
__field(u32, maj_stat)
184+
__string(addr, rqstp->rq_xprt->xpt_remotebuf)
185+
),
186+
187+
TP_fast_assign(
188+
__entry->xid = __be32_to_cpu(rqstp->rq_xid);
189+
__entry->maj_stat = maj_stat;
190+
__assign_str(addr, rqstp->rq_xprt->xpt_remotebuf);
191+
),
192+
193+
TP_printk("addr=%s xid=0x%08x maj_stat=%s",
194+
__get_str(addr), __entry->xid,
195+
__entry->maj_stat == 0 ?
196+
"GSS_S_COMPLETE" : show_gss_status(__entry->maj_stat))
197+
);
198+
199+
#define DEFINE_SVC_GSSAPI_EVENT(name) \
200+
DEFINE_EVENT(rpcgss_svc_gssapi_class, rpcgss_svc_##name, \
201+
TP_PROTO( \
202+
const struct svc_rqst *rqstp, \
203+
u32 maj_stat \
204+
), \
205+
TP_ARGS(rqstp, maj_stat))
206+
207+
DEFINE_SVC_GSSAPI_EVENT(unwrap);
208+
DEFINE_SVC_GSSAPI_EVENT(mic);
209+
210+
TRACE_EVENT(rpcgss_svc_unwrap_failed,
211+
TP_PROTO(
212+
const struct svc_rqst *rqstp
213+
),
214+
215+
TP_ARGS(rqstp),
216+
217+
TP_STRUCT__entry(
218+
__field(u32, xid)
219+
__string(addr, rqstp->rq_xprt->xpt_remotebuf)
220+
),
221+
222+
TP_fast_assign(
223+
__entry->xid = be32_to_cpu(rqstp->rq_xid);
224+
__assign_str(addr, rqstp->rq_xprt->xpt_remotebuf);
225+
),
226+
227+
TP_printk("addr=%s xid=0x%08x", __get_str(addr), __entry->xid)
228+
);
229+
230+
TRACE_EVENT(rpcgss_svc_seqno_bad,
231+
TP_PROTO(
232+
const struct svc_rqst *rqstp,
233+
u32 expected,
234+
u32 received
235+
),
236+
237+
TP_ARGS(rqstp, expected, received),
238+
239+
TP_STRUCT__entry(
240+
__field(u32, expected)
241+
__field(u32, received)
242+
__field(u32, xid)
243+
__string(addr, rqstp->rq_xprt->xpt_remotebuf)
244+
),
245+
246+
TP_fast_assign(
247+
__entry->expected = expected;
248+
__entry->received = received;
249+
__entry->xid = __be32_to_cpu(rqstp->rq_xid);
250+
__assign_str(addr, rqstp->rq_xprt->xpt_remotebuf);
251+
),
252+
253+
TP_printk("addr=%s xid=0x%08x expected seqno %u, received seqno %u",
254+
__get_str(addr), __entry->xid,
255+
__entry->expected, __entry->received)
256+
);
257+
173258
TRACE_EVENT(rpcgss_svc_accept_upcall,
174259
TP_PROTO(
175-
__be32 xid,
260+
const struct svc_rqst *rqstp,
176261
u32 major_status,
177262
u32 minor_status
178263
),
179264

180-
TP_ARGS(xid, major_status, minor_status),
265+
TP_ARGS(rqstp, major_status, minor_status),
181266

182267
TP_STRUCT__entry(
183-
__field(u32, xid)
184268
__field(u32, minor_status)
185269
__field(unsigned long, major_status)
270+
__field(u32, xid)
271+
__string(addr, rqstp->rq_xprt->xpt_remotebuf)
186272
),
187273

188274
TP_fast_assign(
189-
__entry->xid = be32_to_cpu(xid);
190275
__entry->minor_status = minor_status;
191276
__entry->major_status = major_status;
277+
__entry->xid = be32_to_cpu(rqstp->rq_xid);
278+
__assign_str(addr, rqstp->rq_xprt->xpt_remotebuf);
192279
),
193280

194-
TP_printk("xid=0x%08x major_status=%s (0x%08lx) minor_status=%u",
195-
__entry->xid, __entry->major_status == 0 ? "GSS_S_COMPLETE" :
196-
show_gss_status(__entry->major_status),
281+
TP_printk("addr=%s xid=0x%08x major_status=%s (0x%08lx) minor_status=%u",
282+
__get_str(addr), __entry->xid,
283+
(__entry->major_status == 0) ? "GSS_S_COMPLETE" :
284+
show_gss_status(__entry->major_status),
197285
__entry->major_status, __entry->minor_status
198286
)
199287
);
200288

201-
TRACE_EVENT(rpcgss_svc_accept,
289+
TRACE_EVENT(rpcgss_svc_authenticate,
202290
TP_PROTO(
203-
__be32 xid,
204-
size_t len
291+
const struct svc_rqst *rqstp,
292+
const struct rpc_gss_wire_cred *gc
205293
),
206294

207-
TP_ARGS(xid, len),
295+
TP_ARGS(rqstp, gc),
208296

209297
TP_STRUCT__entry(
298+
__field(u32, seqno)
210299
__field(u32, xid)
211-
__field(size_t, len)
300+
__string(addr, rqstp->rq_xprt->xpt_remotebuf)
212301
),
213302

214303
TP_fast_assign(
215-
__entry->xid = be32_to_cpu(xid);
216-
__entry->len = len;
304+
__entry->xid = be32_to_cpu(rqstp->rq_xid);
305+
__entry->seqno = gc->gc_seq;
306+
__assign_str(addr, rqstp->rq_xprt->xpt_remotebuf);
217307
),
218308

219-
TP_printk("xid=0x%08x len=%zu",
220-
__entry->xid, __entry->len
221-
)
309+
TP_printk("addr=%s xid=0x%08x seqno=%u", __get_str(addr),
310+
__entry->xid, __entry->seqno)
222311
);
223312

224313

@@ -371,37 +460,64 @@ TRACE_EVENT(rpcgss_update_slack,
371460

372461
DECLARE_EVENT_CLASS(rpcgss_svc_seqno_class,
373462
TP_PROTO(
374-
__be32 xid,
463+
const struct svc_rqst *rqstp,
375464
u32 seqno
376465
),
377466

378-
TP_ARGS(xid, seqno),
467+
TP_ARGS(rqstp, seqno),
379468

380469
TP_STRUCT__entry(
381470
__field(u32, xid)
382471
__field(u32, seqno)
383472
),
384473

385474
TP_fast_assign(
386-
__entry->xid = be32_to_cpu(xid);
475+
__entry->xid = be32_to_cpu(rqstp->rq_xid);
387476
__entry->seqno = seqno;
388477
),
389478

390-
TP_printk("xid=0x%08x seqno=%u, request discarded",
479+
TP_printk("xid=0x%08x seqno=%u",
391480
__entry->xid, __entry->seqno)
392481
);
393482

394483
#define DEFINE_SVC_SEQNO_EVENT(name) \
395-
DEFINE_EVENT(rpcgss_svc_seqno_class, rpcgss_svc_##name, \
484+
DEFINE_EVENT(rpcgss_svc_seqno_class, rpcgss_svc_seqno_##name, \
396485
TP_PROTO( \
397-
__be32 xid, \
486+
const struct svc_rqst *rqstp, \
398487
u32 seqno \
399488
), \
400-
TP_ARGS(xid, seqno))
489+
TP_ARGS(rqstp, seqno))
401490

402-
DEFINE_SVC_SEQNO_EVENT(large_seqno);
403-
DEFINE_SVC_SEQNO_EVENT(old_seqno);
491+
DEFINE_SVC_SEQNO_EVENT(large);
492+
DEFINE_SVC_SEQNO_EVENT(seen);
404493

494+
TRACE_EVENT(rpcgss_svc_seqno_low,
495+
TP_PROTO(
496+
const struct svc_rqst *rqstp,
497+
u32 seqno,
498+
u32 min,
499+
u32 max
500+
),
501+
502+
TP_ARGS(rqstp, seqno, min, max),
503+
504+
TP_STRUCT__entry(
505+
__field(u32, xid)
506+
__field(u32, seqno)
507+
__field(u32, min)
508+
__field(u32, max)
509+
),
510+
511+
TP_fast_assign(
512+
__entry->xid = be32_to_cpu(rqstp->rq_xid);
513+
__entry->seqno = seqno;
514+
__entry->min = min;
515+
__entry->max = max;
516+
),
517+
518+
TP_printk("xid=0x%08x seqno=%u window=[%u..%u]",
519+
__entry->xid, __entry->seqno, __entry->min, __entry->max)
520+
);
405521

406522
/**
407523
** gssd upcall related trace events

0 commit comments

Comments
 (0)