From: Chuck Lever III <chuck.lever@oracle.com>
To: Steven Rostedt <rostedt@goodmis.org>
Cc: LKML <linux-kernel@vger.kernel.org>
Subject: Re: possible trace_printk() bug in v5.19-rc1
Date: Sat, 18 Jun 2022 01:28:49 +0000 [thread overview]
Message-ID: <3BAD2CD9-3A34-4140-A28C-0FE798B83C41@oracle.com> (raw)
In-Reply-To: <20220617155019.373adda7@gandalf.local.home>
> On Jun 17, 2022, at 3:50 PM, Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Thu, 16 Jun 2022 15:36:43 +0000
> Chuck Lever III <chuck.lever@oracle.com> wrote:
>
>>> Did you remove any modules before displaying the trace?
>>
>> I haven't explicitly removed nfsd.ko, and lsmod says it's still there.
>> And, trace_printk was working as expected on v5.18.
>
> Are you sure?
Yes, I'm sure. I just checked out v5.18 and built it with the
same CONFIG. trace_printk() on that kernel generates function
names as expected.
> I just checkout v5.19-rc2 and added the below patch. Then I did the
> following:
>
> # rmmod bridge
>
> # trace-cmd start -p function -l :mod:bridge
>
> # insmod bridge
>
> # trace-cmd show
> # tracer: function
> #
> # entries-in-buffer/entries-written: 23/23 #P:8
> #
> # _-----=> irqs-off/BH-disabled
> # / _----=> need-resched
> # | / _---=> hardirq/softirq
> # || / _--=> preempt-depth
> # ||| / _-=> migrate-disable
> # |||| / delay
> # TASK-PID CPU# ||||| TIMESTAMP FUNCTION
> # | | | ||||| | |
> modprobe-2155 [005] ...1. 4732.051406: br_init <-do_one_initcall
> modprobe-2155 [005] ..... 4732.051408: br_init: here in bridge
> modprobe-2155 [005] ...1. 4732.051408: br_fdb_init <-br_init
> modprobe-2155 [005] ...1. 4732.051418: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051418: br_device_event: this is an event
> modprobe-2155 [005] ...1. 4732.051418: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051418: br_device_event: this is an event
> modprobe-2155 [005] ...1. 4732.051418: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051419: br_device_event: this is an event
> modprobe-2155 [005] ...1. 4732.051419: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051419: br_device_event: this is an event
> modprobe-2155 [005] ...1. 4732.051419: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051419: br_device_event: this is an event
> modprobe-2155 [005] ...1. 4732.051419: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051420: br_device_event: this is an event
> modprobe-2155 [005] ...1. 4732.051420: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051420: br_device_event: this is an event
> modprobe-2155 [005] ...1. 4732.051420: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051420: br_device_event: this is an event
> modprobe-2155 [005] ...1. 4732.051420: br_device_event <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051420: br_device_event: this is an event
> modprobe-2155 [005] ...1. 4732.051421: br_netlink_init <-br_init
> modprobe-2155 [005] ...1. 4732.051421: br_mdb_init <-br_netlink_init
>
> # rmmod bridge
>
> # trace-cmd show
> # tracer: function
> #
> # entries-in-buffer/entries-written: 56/56 #P:8
> #
> # _-----=> irqs-off/BH-disabled
> # / _----=> need-resched
> # | / _---=> hardirq/softirq
> # || / _--=> preempt-depth
> # ||| / _-=> migrate-disable
> # |||| / delay
> # TASK-PID CPU# ||||| TIMESTAMP FUNCTION
> # | | | ||||| | |
> modprobe-2155 [005] ...1. 4732.051406: 0xffffffffc0cc7000 <-do_one_initcall
> modprobe-2155 [005] ..... 4732.051408: 0xffffffffc0cc702b: here in bridge
> modprobe-2155 [005] ...1. 4732.051408: 0xffffffffc0cc7101 <-0xffffffffc0cc7043
> modprobe-2155 [005] ...1. 4732.051418: 0xffffffffc0d81340 <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051418: 0xffffffffc0d81345: this is an event
> modprobe-2155 [005] ...1. 4732.051418: 0xffffffffc0d81340 <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051418: 0xffffffffc0d81345: this is an event
> modprobe-2155 [005] ...1. 4732.051418: 0xffffffffc0d81340 <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051419: 0xffffffffc0d81345: this is an event
> modprobe-2155 [005] ...1. 4732.051419: 0xffffffffc0d81340 <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051419: 0xffffffffc0d81345: this is an event
> modprobe-2155 [005] ...1. 4732.051419: 0xffffffffc0d81340 <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051419: 0xffffffffc0d81345: this is an event
> modprobe-2155 [005] ...1. 4732.051419: 0xffffffffc0d81340 <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051420: 0xffffffffc0d81345: this is an event
> modprobe-2155 [005] ...1. 4732.051420: 0xffffffffc0d81340 <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051420: 0xffffffffc0d81345: this is an event
> modprobe-2155 [005] ...1. 4732.051420: 0xffffffffc0d81340 <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051420: 0xffffffffc0d81345: this is an event
> modprobe-2155 [005] ...1. 4732.051420: 0xffffffffc0d81340 <-call_netdevice_register_net_notifiers
> modprobe-2155 [005] ..... 4732.051420: 0xffffffffc0d81345: this is an event
> modprobe-2155 [005] ...1. 4732.051421: 0xffffffffc0cc7132 <-0xffffffffc0cc70a3
> modprobe-2155 [005] ...1. 4732.051421: 0xffffffffc0da1500 <-0xffffffffc0cc713e
> kworker/u16:2-2023 [004] ...1. 4737.946576: 0xffffffffc0d81340 <-raw_notifier_call_chain
> kworker/u16:2-2023 [004] ..... 4737.946578: 0xffffffffc0d81345: this is an event
> kworker/u16:2-2023 [004] ...1. 4737.946634: 0xffffffffc0d8e1a0 <-if_nlmsg_size
> kworker/u16:2-2023 [004] ...1. 4737.946735: 0xffffffffc0d81340 <-raw_notifier_call_chain
> kworker/u16:2-2023 [004] ..... 4737.946735: 0xffffffffc0d81345: this is an event
> kworker/u16:2-2023 [004] ...1. 4737.946833: 0xffffffffc0d81340 <-raw_notifier_call_chain
> kworker/u16:2-2023 [004] ..... 4737.946833: 0xffffffffc0d81345: this is an event
> kworker/u16:2-2023 [004] ...1. 4737.946834: 0xffffffffc0d8e1a0 <-if_nlmsg_size
> kworker/u16:2-2023 [004] ...1. 4737.957648: 0xffffffffc0d81190 <-cleanup_net
> rmmod-2206 [000] ...1. 5739.459376: 0xffffffffc0d8f880 <-0xffffffffc0da3d1d
> rmmod-2206 [000] ...1. 5739.459378: 0xffffffffc0da1570 <-0xffffffffc0d8f88a
> rmmod-2206 [000] ...1. 5739.471367: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471368: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.471369: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471369: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.471369: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471369: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.471370: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471370: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.471370: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471370: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.471370: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471370: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.471371: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471371: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.471371: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471371: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.471371: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471372: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.471372: 0xffffffffc0d81340 <-call_netdevice_unregister_notifiers
> rmmod-2206 [000] ..... 5739.471372: 0xffffffffc0d81345: this is an event
> rmmod-2206 [000] ...1. 5739.477366: 0xffffffffc0d81190 <-unregister_pernet_operations
> rmmod-2206 [000] ...1. 5739.477375: 0xffffffffc0d84910 <-__do_sys_delete_module.constprop.0
>
> Before removing the module, the names were all present. Then after I
> removed the module, they did not exist.
>
> Other than that, I cannot reproduce the issue.
>
> -- Steve
>
>
> diff --git a/net/bridge/br.c b/net/bridge/br.c
> index 96e91d69a9a8..4067760d3763 100644
> --- a/net/bridge/br.c
> +++ b/net/bridge/br.c
> @@ -36,6 +36,7 @@ static int br_device_event(struct notifier_block *unused, unsigned long event, v
> bool changed_addr;
> int err;
>
> + trace_printk("this is an event\n");
> if (netif_is_bridge_master(dev)) {
> err = br_vlan_bridge_event(dev, event, ptr);
> if (err)
> @@ -385,6 +386,7 @@ static int __init br_init(void)
> return err;
> }
>
> + trace_printk("here in bridge\n");
> err = br_fdb_init();
> if (err)
> goto err_out;
--
Chuck Lever
next prev parent reply other threads:[~2022-06-18 1:29 UTC|newest]
Thread overview: 26+ messages / expand[flat|nested] mbox.gz Atom feed top
2022-06-16 15:22 Chuck Lever III
2022-06-16 15:34 ` Steven Rostedt
2022-06-16 15:36 ` Chuck Lever III
2022-06-16 15:43 ` Steven Rostedt
2022-06-16 18:07 ` Chuck Lever III
2022-06-17 19:50 ` Steven Rostedt
2022-06-18 1:28 ` Chuck Lever III [this message]
2022-06-20 0:57 ` Chuck Lever III
2022-06-24 18:23 ` Chuck Lever III
2022-06-24 23:08 ` Steven Rostedt
2022-06-25 17:15 ` Chuck Lever III
2022-06-25 17:45 ` Steven Rostedt
2022-06-25 18:28 ` John 'Warthog9' Hawley
2022-06-26 3:01 ` John 'Warthog9' Hawley
2022-06-27 17:08 ` Chuck Lever III
2022-06-27 17:11 ` Steven Rostedt
2022-06-27 17:19 ` Chuck Lever III
2022-06-27 19:01 ` Steven Rostedt
2022-06-28 15:24 ` Steven Rostedt
2022-06-25 18:50 ` Chuck Lever III
2022-06-25 23:01 ` Steven Rostedt
2022-06-26 17:09 ` Chuck Lever III
2022-06-27 15:43 ` Steven Rostedt
2022-06-27 15:51 ` Chuck Lever III
2022-06-27 16:02 ` Steven Rostedt
2022-06-28 3:59 ` Steven Rostedt
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=3BAD2CD9-3A34-4140-A28C-0FE798B83C41@oracle.com \
--to=chuck.lever@oracle.com \
--cc=linux-kernel@vger.kernel.org \
--cc=rostedt@goodmis.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox
all inboxes | Powered by JetHome®