lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <3BAD2CD9-3A34-4140-A28C-0FE798B83C41@oracle.com>
Date:   Sat, 18 Jun 2022 01:28:49 +0000
From:   Chuck Lever III <chuck.lever@...cle.com>
To:     Steven Rostedt <rostedt@...dmis.org>
CC:     LKML <linux-kernel@...r.kernel.org>
Subject: Re: possible trace_printk() bug in v5.19-rc1



> On Jun 17, 2022, at 3:50 PM, Steven Rostedt <rostedt@...dmis.org> wrote:
> 
> On Thu, 16 Jun 2022 15:36:43 +0000
> Chuck Lever III <chuck.lever@...cle.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



Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ