Subject: linux-next: runtime warning in next-20220125

From: Stephen Rothwell <[email-masked]>
Date: Tue, 25 Jan 2022 16:05:05 +1100

Hi all,

My qemu boot test of a powerpc pseries_le_defconfig kernel produces the
following trace:

------------[ cut here ]------------
WARNING: CPU: 0 PID: 0 at kernel/trace/trace_events.c:417 trace_event_raw_init+0x194/0x730
Modules linked in:
CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.17.0-rc1 #2
NIP:  c0000000002bdbb4 LR: c0000000002bdcb0 CTR: c0000000002bdb70
REGS: c00000000278ba10 TRAP: 0700   Not tainted  (5.17.0-rc1)
MSR:  8000000002021033 <SF,VEC,ME,IR,DR,RI,LE>  CR: 44000282  XER: 20000000
CFAR: c0000000002bdb38 IRQMASK: 1 
GPR00: c0000000002bdc98 c00000000278bcb0 c00000000278d300 0000000000000000 
GPR04: 000000000000002c 0000000000000005 000000000000023f c0000000002bdb3c 
GPR08: 0000000000000000 0000000000000000 0000000000000000 0000000000000000 
GPR12: c0000000002bda20 c000000002960000 0000000000000000 0000000000000000 
GPR16: 0000000002bf00d0 000000007e68ebc8 ffffffffffffffff 000508b58019388f 
GPR20: 0000000000000001 c000000000faf800 0000000000000005 0000000000000000 
GPR24: 0000000000000000 0000000000000003 0000000000000000 0000000000000000 
GPR28: c0000000026fefc0 c0000000026f8050 0000000000000251 c0000000026f82a1 
NIP [c0000000002bdbb4] trace_event_raw_init+0x194/0x730
LR [c0000000002bdcb0] trace_event_raw_init+0x290/0x730
Call Trace:
[c00000000278bcb0] [c0000000002bdc98] trace_event_raw_init+0x278/0x730 (unreliable)
[c00000000278bda0] [c0000000002badb8] event_init+0x68/0xf0
[c00000000278be10] [c000000002033990] trace_event_init+0xc8/0x334
[c00000000278beb0] [c000000002033004] trace_init+0x18/0x2c
[c00000000278bed0] [c0000000020042e0] start_kernel+0x590/0x8cc
[c00000000278bf90] [c00000000000d19c] start_here_common+0x1c/0x600
Instruction dump:
41800438 60000000 60420000 3bde0001 7fdf07b4 7ffdfa14 891f0000 710a00ff 
4082ff5c 2c390000 38600000 41820320 <0fe00000> f9c10060 f9e10068 fa010070 
---[ end trace 0000000000000000 ]---
event svc_xprt_accept has unsafe dereference of argument 1
print_fmt: "server=%pISpc client=%pISpc flags=%s protocol=%s service=%s", __get_sockaddr(server), __get_sockaddr(client), __print_flags(REC->flags, "|", { (1UL << 0), "XPT_BUSY"}, { (1UL << 1), "XPT_CONN"}, { (1UL << 2), "XPT_CLOSE"}, { (1UL << 3), "XPT_DATA"}, { (1UL << 4), "XPT_TEMP"}, { (1UL << 6), "XPT_DEAD"}, { (1UL << 7), "XPT_CHNGBUF"}, { (1UL << 8), "XPT_DEFERRED"}, { (1UL << 9), "XPT_OLD"}, { (1UL << 10), "XPT_LISTENER"}, { (1UL << 11), "XPT_CACHE_AUTH"}, { (1UL << 12), "XPT_LOCAL"}, { (1UL << 13), "XPT_KILL_TEMP"}, { (1UL << 14), "XPT_CONG_CTRL"}), __get_str(protocol), __get_str(service)
event svc_xprt_free has unsafe dereference of argument 1
print_fmt: "server=%pISpc client=%pISpc flags=%s", __get_sockaddr(server), __get_sockaddr(client), __print_flags(REC->flags, "|", { (1UL << 0), "XPT_BUSY"}, { (1UL << 1), "XPT_CONN"}, { (1UL << 2), "XPT_CLOSE"}, { (1UL << 3), "XPT_DATA"}, { (1UL << 4), "XPT_TEMP"}, { (1UL << 6), "XPT_DEAD"}, { (1UL << 7), "XPT_CHNGBUF"}, { (1UL << 8), "XPT_DEFERRED"}, { (1UL << 9), "XPT_OLD"}, { (1UL << 10), "XPT_LISTENER"}, { (1UL << 11), "XPT_CACHE_AUTH"}, { (1UL << 12), "XPT_LOCAL"}, { (1UL << 13), "XPT_KILL_TEMP"}, { (1UL << 14), "XPT_CONG_CTRL"})
event svc_xprt_detach has unsafe dereference of argument 1
print_fmt: "server=%pISpc client=%pISpc flags=%s", __get_sockaddr(server), __get_sockaddr(client), __print_flags(REC->flags, "|", { (1UL << 0), "XPT_BUSY"}, { (1UL << 1), "XPT_CONN"}, { (1UL << 2), "XPT_CLOSE"}, { (1UL << 3), "XPT_DATA"}, { (1UL << 4), "XPT_TEMP"}, { (1UL << 6), "XPT_DEAD"}, { (1UL << 7), "XPT_CHNGBUF"}, { (1UL << 8), "XPT_DEFERRED"}, { (1UL << 9), "XPT_OLD"}, { (1UL << 10), "XPT_LISTENER"}, { (1UL << 11), "XPT_CACHE_AUTH"}, { (1UL << 12), "XPT_LOCAL"}, { (1UL << 13), "XPT_KILL_TEMP"}, { (1UL << 14), "XPT_CONG_CTRL"})
event svc_xprt_close has unsafe dereference of argument 1
print_fmt: "server=%pISpc client=%pISpc flags=%s", __get_sockaddr(server), __get_sockaddr(client), __print_flags(REC->flags, "|", { (1UL << 0), "XPT_BUSY"}, { (1UL << 1), "XPT_CONN"}, { (1UL << 2), "XPT_CLOSE"}, { (1UL << 3), "XPT_DATA"}, { (1UL << 4), "XPT_TEMP"}, { (1UL << 6), "XPT_DEAD"}, { (1UL << 7), "XPT_CHNGBUF"}, { (1UL << 8), "XPT_DEFERRED"}, { (1UL << 9), "XPT_OLD"}, { (1UL << 10), "XPT_LISTENER"}, { (1UL << 11), "XPT_CACHE_AUTH"}, { (1UL << 12), "XPT_LOCAL"}, { (1UL << 13), "XPT_KILL_TEMP"}, { (1UL << 14), "XPT_CONG_CTRL"})
event svc_xprt_no_write_space has unsafe dereference of argument 1
print_fmt: "server=%pISpc client=%pISpc flags=%s", __get_sockaddr(server), __get_sockaddr(client), __print_flags(REC->flags, "|", { (1UL << 0), "XPT_BUSY"}, { (1UL << 1), "XPT_CONN"}, { (1UL << 2), "XPT_CLOSE"}, { (1UL << 3), "XPT_DATA"}, { (1UL << 4), "XPT_TEMP"}, { (1UL << 6), "XPT_DEAD"}, { (1UL << 7), "XPT_CHNGBUF"}, { (1UL << 8), "XPT_DEFERRED"}, { (1UL << 9), "XPT_OLD"}, { (1UL << 10), "XPT_LISTENER"}, { (1UL << 11), "XPT_CACHE_AUTH"}, { (1UL << 12), "XPT_LOCAL"}, { (1UL << 13), "XPT_KILL_TEMP"}, { (1UL << 14), "XPT_CONG_CTRL"})
event svc_xprt_dequeue has unsafe dereference of argument 1
print_fmt: "server=%pISpc client=%pISpc flags=%s wakeup-us=%lu", __get_sockaddr(server), __get_sockaddr(client), __print_flags(REC->flags, "|", { (1UL << 0), "XPT_BUSY"}, { (1UL << 1), "XPT_CONN"}, { (1UL << 2), "XPT_CLOSE"}, { (1UL << 3), "XPT_DATA"}, { (1UL << 4), "XPT_TEMP"}, { (1UL << 6), "XPT_DEAD"}, { (1UL << 7), "XPT_CHNGBUF"}, { (1UL << 8), "XPT_DEFERRED"}, { (1UL << 9), "XPT_OLD"}, { (1UL << 10), "XPT_LISTENER"}, { (1UL << 11), "XPT_CACHE_AUTH"}, { (1UL << 12), "XPT_LOCAL"}, { (1UL << 13), "XPT_KILL_TEMP"}, { (1UL << 14), "XPT_CONG_CTRL"}), REC->wakeup
event svc_xprt_enqueue has unsafe dereference of argument 1
print_fmt: "server=%pISpc client=%pISpc flags=%s pid=%d", __get_sockaddr(server), __get_sockaddr(client), __print_flags(REC->flags, "|", { (1UL << 0), "XPT_BUSY"}, { (1UL << 1), "XPT_CONN"}, { (1UL << 2), "XPT_CLOSE"}, { (1UL << 3), "XPT_DATA"}, { (1UL << 4), "XPT_TEMP"}, { (1UL << 6), "XPT_DEAD"}, { (1UL << 7), "XPT_CHNGBUF"}, { (1UL << 8), "XPT_DEFERRED"}, { (1UL << 9), "XPT_OLD"}, { (1UL << 10), "XPT_LISTENER"}, { (1UL << 11), "XPT_CACHE_AUTH"}, { (1UL << 12), "XPT_LOCAL"}, { (1UL << 13), "XPT_KILL_TEMP"}, { (1UL << 14), "XPT_CONG_CTRL"}), REC->pid
event svc_xprt_create_err has unsafe dereference of argument 1
print_fmt: "addr=%pISpc program=%s protocol=%s error=%ld", __get_sockaddr(addr), __get_str(program), __get_str(protocol), REC->error
event svc_stats_latency has unsafe dereference of argument 2
print_fmt: "xid=0x%08x server=%pISpc client=%pISpc proc=%s execute-us=%lu", REC->xid, __get_sockaddr(server), __get_sockaddr(client), __get_str(procedure), REC->execute
event svc_send has unsafe dereference of argument 2
print_fmt: "xid=0x%08x server=%pISpc client=%pISpc status=%d flags=%s", REC->xid, __get_sockaddr(server), __get_sockaddr(client), REC->status, __print_flags(REC->flags, "|", { ((((1UL))) << ((0))), "SECURE" }, { ((((1UL))) << ((1))), "LOCAL" }, { ((((1UL))) << ((2))), "USEDEFERRAL" }, { ((((1UL))) << ((3))), "DROPME" }, { ((((1UL))) << ((4))), "SPLICE_OK" }, { ((((1UL))) << ((5))), "VICTIM" }, { ((((1UL))) << ((6))), "BUSY" }, { ((((1UL))) << ((7))), "DATA" })
event svc_drop has unsafe dereference of argument 2
print_fmt: "xid=0x%08x server=%pISpc client=%pISpc flags=%s", REC->xid, __get_sockaddr(server), __get_sockaddr(client), __print_flags(REC->flags, "|", { ((((1UL))) << ((0))), "SECURE" }, { ((((1UL))) << ((1))), "LOCAL" }, { ((((1UL))) << ((2))), "USEDEFERRAL" }, { ((((1UL))) << ((3))), "DROPME" }, { ((((1UL))) << ((4))), "SPLICE_OK" }, { ((((1UL))) << ((5))), "VICTIM" }, { ((((1UL))) << ((6))), "BUSY" }, { ((((1UL))) << ((7))), "DATA" })
event svc_defer has unsafe dereference of argument 2
print_fmt: "xid=0x%08x server=%pISpc client=%pISpc flags=%s", REC->xid, __get_sockaddr(server), __get_sockaddr(client), __print_flags(REC->flags, "|", { ((((1UL))) << ((0))), "SECURE" }, { ((((1UL))) << ((1))), "LOCAL" }, { ((((1UL))) << ((2))), "USEDEFERRAL" }, { ((((1UL))) << ((3))), "DROPME" }, { ((((1UL))) << ((4))), "SPLICE_OK" }, { ((((1UL))) << ((5))), "VICTIM" }, { ((((1UL))) << ((6))), "BUSY" }, { ((((1UL))) << ((7))), "DATA" })
event svc_authenticate has unsafe dereference of argument 2
print_fmt: "xid=0x%08x server=%pISpc client=%pISpc auth_res=%s auth_stat=%s", REC->xid, __get_sockaddr(server), __get_sockaddr(client), __print_symbolic(REC->svc_status, { 1, "SVC_GARBAGE" }, { 2, "SVC_SYSERR" }, { 3, "SVC_VALID" }, { 4, "SVC_NEGATIVE" }, { 5, "SVC_OK" }, { 6, "SVC_DROP" }, { 7, "SVC_CLOSE" }, { 8, "SVC_DENIED" }, { 9, "SVC_PENDING" }, { 10, "SVC_COMPLETE" }), __print_symbolic(REC->auth_stat, { RPC_AUTH_OK, "AUTH_OK" }, { RPC_AUTH_BADCRED, "BADCRED" }, { RPC_AUTH_REJECTEDCRED, "REJECTEDCRED" }, { RPC_AUTH_BADVERF, "BADVERF" }, { RPC_AUTH_REJECTEDVERF, "REJECTEDVERF" }, { RPC_AUTH_TOOWEAK, "TOOWEAK" }, { RPCSEC_GSS_CREDPROBLEM, "GSS_CREDPROBLEM" }, { RPCSEC_GSS_CTXPROBLEM, "GSS_CTXPROBLEM" })

I have no idea what has caused this :-(  Maybe commit

  5544d5318802 ("SUNRPC: Same as SVC_RQST_ENDPOINT, but without the xid")

-- 
Cheers,
Stephen Rothwell