All of lore.kernel.org
 help / color / mirror / Atom feed
From: Steven Rostedt <rostedt@goodmis.org>
To: Chuck Lever III <chuck.lever@oracle.com>
Cc: LKML <linux-kernel@vger.kernel.org>
Subject: Re: possible trace_printk() bug in v5.19-rc1
Date: Fri, 17 Jun 2022 15:50:19 -0400	[thread overview]
Message-ID: <20220617155019.373adda7@gandalf.local.home> (raw)
In-Reply-To: <E309A098-DA06-490D-A75C-E6295C2987B9@oracle.com>

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?

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;

  parent reply	other threads:[~2022-06-17 19:50 UTC|newest]

Thread overview: 26+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2022-06-16 15:22 possible trace_printk() bug in v5.19-rc1 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 [this message]
2022-06-18  1:28       ` Chuck Lever III
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=20220617155019.373adda7@gandalf.local.home \
    --to=rostedt@goodmis.org \
    --cc=chuck.lever@oracle.com \
    --cc=linux-kernel@vger.kernel.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 an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.