2009-10-03 10:53:17

by Matti Aarnio

[permalink] [raw]
Subject: ftrace WARNING during boot

This is perhaps already fixed, as I have two a bit newer kernels than this one,
but reporting is better than being silent..

.....................
kernel: rtc_cmos 00:04: setting system clock to 2009-10-02 23:21:17 UTC (1254525677)
kernel: Initalizing network drop monitor service
kernel: Freeing unused kernel memory: 3196k freed
kernel: NX-protecting the kernel data: ffffffff8150e000, 4469 pages
kernel: Write protecting the kernel read-only data: 7392k
kernel: dracut: dracut-002-2.gitc53acc30.fc12
kernel: udev: starting version 145
kernel: usb 1-5: new high speed USB device using ehci_hcd and address 4
kernel: ------------[ cut here ]------------
kernel: WARNING: at kernel/trace/ftrace.c:1003 ftrace_bug+0x198/0x27e() (Not tainted)
kernel: Hardware name: System Product Name
kernel: Modules linked in: i2c_core(+)
kernel: Pid: 87, comm: modprobe Not tainted 2.6.31-33.fc12.x86_64 #1
kernel: Call Trace:
kernel: [<ffffffff810642ec>] warn_slowpath_common+0x95/0xc3
kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
kernel: [<ffffffff81064341>] warn_slowpath_null+0x27/0x3d
kernel: [<ffffffff810d4ace>] ftrace_bug+0x198/0x27e
kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
kernel: [<ffffffff810d5d26>] ftrace_convert_nops+0x201/0x2b9
kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
kernel: [<ffffffff810d5e2a>] ftrace_module_notify+0x4c/0x7f
kernel: [<ffffffff81509c65>] notifier_call_chain+0x72/0xba
kernel: [<ffffffff81086e71>] ? __blocking_notifier_call_chain+0x4c/0x8e
kernel: [<ffffffff81086e88>] __blocking_notifier_call_chain+0x63/0x8e
kernel: [<ffffffff81086eda>] blocking_notifier_call_chain+0x27/0x3d
kernel: [<ffffffff810a472a>] sys_init_module+0xb7/0x249
kernel: [<ffffffff81011f42>] system_call_fastpath+0x16/0x1b
kernel: ---[ end trace fbf9054ae0f212c7 ]---
kernel: ftrace faulted on writing [<ffffffffa0003072>] i2c_new_dummy+0x8/0x5e [i2c_core]
kernel: usb 1-5: New USB device found, idVendor=0424, idProduct=2504
kernel: usb 1-5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
kernel: usb 1-5: configuration #1 chosen from 1 choice
kernel: hub 1-5:1.0: USB hub found
kernel: hub 1-5:1.0: 4 ports detected
..................


2009-10-03 11:00:05

by Frederic Weisbecker

[permalink] [raw]
Subject: Re: ftrace WARNING during boot

On Sat, Oct 03, 2009 at 01:53:18PM +0300, Matti Aarnio wrote:
> This is perhaps already fixed, as I have two a bit newer kernels than this one,
> but reporting is better than being silent..


Hi,

Which kernel is this? Does it happen in the current 2.6.32-rc1 ?

Thanks.


>
> .....................
> kernel: rtc_cmos 00:04: setting system clock to 2009-10-02 23:21:17 UTC (1254525677)
> kernel: Initalizing network drop monitor service
> kernel: Freeing unused kernel memory: 3196k freed
> kernel: NX-protecting the kernel data: ffffffff8150e000, 4469 pages
> kernel: Write protecting the kernel read-only data: 7392k
> kernel: dracut: dracut-002-2.gitc53acc30.fc12
> kernel: udev: starting version 145
> kernel: usb 1-5: new high speed USB device using ehci_hcd and address 4
> kernel: ------------[ cut here ]------------
> kernel: WARNING: at kernel/trace/ftrace.c:1003 ftrace_bug+0x198/0x27e() (Not tainted)
> kernel: Hardware name: System Product Name
> kernel: Modules linked in: i2c_core(+)
> kernel: Pid: 87, comm: modprobe Not tainted 2.6.31-33.fc12.x86_64 #1
> kernel: Call Trace:
> kernel: [<ffffffff810642ec>] warn_slowpath_common+0x95/0xc3
> kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> kernel: [<ffffffff81064341>] warn_slowpath_null+0x27/0x3d
> kernel: [<ffffffff810d4ace>] ftrace_bug+0x198/0x27e
> kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> kernel: [<ffffffff810d5d26>] ftrace_convert_nops+0x201/0x2b9
> kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> kernel: [<ffffffff810d5e2a>] ftrace_module_notify+0x4c/0x7f
> kernel: [<ffffffff81509c65>] notifier_call_chain+0x72/0xba
> kernel: [<ffffffff81086e71>] ? __blocking_notifier_call_chain+0x4c/0x8e
> kernel: [<ffffffff81086e88>] __blocking_notifier_call_chain+0x63/0x8e
> kernel: [<ffffffff81086eda>] blocking_notifier_call_chain+0x27/0x3d
> kernel: [<ffffffff810a472a>] sys_init_module+0xb7/0x249
> kernel: [<ffffffff81011f42>] system_call_fastpath+0x16/0x1b
> kernel: ---[ end trace fbf9054ae0f212c7 ]---
> kernel: ftrace faulted on writing [<ffffffffa0003072>] i2c_new_dummy+0x8/0x5e [i2c_core]
> kernel: usb 1-5: New USB device found, idVendor=0424, idProduct=2504
> kernel: usb 1-5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
> kernel: usb 1-5: configuration #1 chosen from 1 choice
> kernel: hub 1-5:1.0: USB hub found
> kernel: hub 1-5:1.0: 4 ports detected
> ..................
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/

2009-10-03 11:28:49

by Matti Aarnio

[permalink] [raw]
Subject: Re: ftrace WARNING during boot

On Sat, Oct 03, 2009 at 01:00:03PM +0200, Frederic Weisbecker wrote:
> On Sat, Oct 03, 2009 at 01:53:18PM +0300, Matti Aarnio wrote:
> > This is perhaps already fixed, as I have two a bit newer kernels than this one,
> > but reporting is better than being silent..
>
>
> Hi,
>
> Which kernel is this? Does it happen in the current 2.6.32-rc1 ?

I do know that reading the trace is difficult, but the asked for information
is down in there. Intentionally put there by the kernel-oops coders, I presume.

I do use vendor kernels, and Fedora 12 beta program has not yet made
2.6.32-rc1 kernel available.

However this does not appear in 2.6.31.1-56.fc12.x86_64 kernel that is lattest
from vendor, but there I have some other troubles why I took a bit older kernel.
(Other troubles with the xfs filesystem lock handling.)

> Thanks.

Best regards, Matti Aarnio

> > .....................
> > kernel: rtc_cmos 00:04: setting system clock to 2009-10-02 23:21:17 UTC (1254525677)
> > kernel: Initalizing network drop monitor service
> > kernel: Freeing unused kernel memory: 3196k freed
> > kernel: NX-protecting the kernel data: ffffffff8150e000, 4469 pages
> > kernel: Write protecting the kernel read-only data: 7392k
> > kernel: dracut: dracut-002-2.gitc53acc30.fc12
> > kernel: udev: starting version 145
> > kernel: usb 1-5: new high speed USB device using ehci_hcd and address 4
> > kernel: ------------[ cut here ]------------
> > kernel: WARNING: at kernel/trace/ftrace.c:1003 ftrace_bug+0x198/0x27e() (Not tainted)
> > kernel: Hardware name: System Product Name
> > kernel: Modules linked in: i2c_core(+)
> > kernel: Pid: 87, comm: modprobe Not tainted 2.6.31-33.fc12.x86_64 #1
> > kernel: Call Trace:
> > kernel: [<ffffffff810642ec>] warn_slowpath_common+0x95/0xc3
> > kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> > kernel: [<ffffffff81064341>] warn_slowpath_null+0x27/0x3d
> > kernel: [<ffffffff810d4ace>] ftrace_bug+0x198/0x27e
> > kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> > kernel: [<ffffffff810d5d26>] ftrace_convert_nops+0x201/0x2b9
> > kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> > kernel: [<ffffffff810d5e2a>] ftrace_module_notify+0x4c/0x7f
> > kernel: [<ffffffff81509c65>] notifier_call_chain+0x72/0xba
> > kernel: [<ffffffff81086e71>] ? __blocking_notifier_call_chain+0x4c/0x8e
> > kernel: [<ffffffff81086e88>] __blocking_notifier_call_chain+0x63/0x8e
> > kernel: [<ffffffff81086eda>] blocking_notifier_call_chain+0x27/0x3d
> > kernel: [<ffffffff810a472a>] sys_init_module+0xb7/0x249
> > kernel: [<ffffffff81011f42>] system_call_fastpath+0x16/0x1b
> > kernel: ---[ end trace fbf9054ae0f212c7 ]---
> > kernel: ftrace faulted on writing [<ffffffffa0003072>] i2c_new_dummy+0x8/0x5e [i2c_core]
> > kernel: usb 1-5: New USB device found, idVendor=0424, idProduct=2504
> > kernel: usb 1-5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
> > kernel: usb 1-5: configuration #1 chosen from 1 choice
> > kernel: hub 1-5:1.0: USB hub found
> > kernel: hub 1-5:1.0: 4 ports detected
> > ..................
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> > the body of a message to [email protected]
> > More majordomo info at http://vger.kernel.org/majordomo-info.html
> > Please read the FAQ at http://www.tux.org/lkml/
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/

2009-10-03 12:00:47

by Frederic Weisbecker

[permalink] [raw]
Subject: Re: ftrace WARNING during boot

On Sat, Oct 03, 2009 at 02:28:50PM +0300, Matti Aarnio wrote:
> On Sat, Oct 03, 2009 at 01:00:03PM +0200, Frederic Weisbecker wrote:
> > On Sat, Oct 03, 2009 at 01:53:18PM +0300, Matti Aarnio wrote:
> > > This is perhaps already fixed, as I have two a bit newer kernels than this one,
> > > but reporting is better than being silent..
> >
> >
> > Hi,
> >
> > Which kernel is this? Does it happen in the current 2.6.32-rc1 ?
>
> I do know that reading the trace is difficult, but the asked for information
> is down in there. Intentionally put there by the kernel-oops coders, I presume.


Ah ok. It's just that I'm not that familiar with fedora's kernels naming :-)


> I do use vendor kernels, and Fedora 12 beta program has not yet made
> 2.6.32-rc1 kernel available.
>
> However this does not appear in 2.6.31.1-56.fc12.x86_64 kernel that is lattest
> from vendor, but there I have some other troubles why I took a bit older kernel.
> (Other troubles with the xfs filesystem lock handling.)



So this looks based on a 2.6.31.1 kernel, more stable. And if it doesn't
happen with it, then it's fine.

That said, it's all about fedora based kernel so it's a bit hard to tell
if it came from fedora adds or vanilla kernel code.

I personnally can't help about Fedora kernels related problems.

Thanks.

2009-10-03 13:59:46

by Ingo Molnar

[permalink] [raw]
Subject: Re: ftrace WARNING during boot


(Cc:-ed more people)

* Matti Aarnio <[email protected]> wrote:

> This is perhaps already fixed, as I have two a bit newer kernels than this one,
> but reporting is better than being silent..
>
> .....................
> kernel: rtc_cmos 00:04: setting system clock to 2009-10-02 23:21:17 UTC (1254525677)
> kernel: Initalizing network drop monitor service
> kernel: Freeing unused kernel memory: 3196k freed
> kernel: NX-protecting the kernel data: ffffffff8150e000, 4469 pages
> kernel: Write protecting the kernel read-only data: 7392k
> kernel: dracut: dracut-002-2.gitc53acc30.fc12
> kernel: udev: starting version 145
> kernel: usb 1-5: new high speed USB device using ehci_hcd and address 4
> kernel: ------------[ cut here ]------------
> kernel: WARNING: at kernel/trace/ftrace.c:1003 ftrace_bug+0x198/0x27e() (Not tainted)
> kernel: Hardware name: System Product Name
> kernel: Modules linked in: i2c_core(+)
> kernel: Pid: 87, comm: modprobe Not tainted 2.6.31-33.fc12.x86_64 #1
> kernel: Call Trace:
> kernel: [<ffffffff810642ec>] warn_slowpath_common+0x95/0xc3
> kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> kernel: [<ffffffff81064341>] warn_slowpath_null+0x27/0x3d
> kernel: [<ffffffff810d4ace>] ftrace_bug+0x198/0x27e
> kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> kernel: [<ffffffff810d5d26>] ftrace_convert_nops+0x201/0x2b9
> kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> kernel: [<ffffffff810d5e2a>] ftrace_module_notify+0x4c/0x7f
> kernel: [<ffffffff81509c65>] notifier_call_chain+0x72/0xba
> kernel: [<ffffffff81086e71>] ? __blocking_notifier_call_chain+0x4c/0x8e
> kernel: [<ffffffff81086e88>] __blocking_notifier_call_chain+0x63/0x8e
> kernel: [<ffffffff81086eda>] blocking_notifier_call_chain+0x27/0x3d
> kernel: [<ffffffff810a472a>] sys_init_module+0xb7/0x249
> kernel: [<ffffffff81011f42>] system_call_fastpath+0x16/0x1b
> kernel: ---[ end trace fbf9054ae0f212c7 ]---
> kernel: ftrace faulted on writing [<ffffffffa0003072>] i2c_new_dummy+0x8/0x5e [i2c_core]
> kernel: usb 1-5: New USB device found, idVendor=0424, idProduct=2504
> kernel: usb 1-5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
> kernel: usb 1-5: configuration #1 chosen from 1 choice
> kernel: hub 1-5:1.0: USB hub found
> kernel: hub 1-5:1.0: 4 ports detected
> ..................
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/

2009-10-03 14:01:06

by Ingo Molnar

[permalink] [raw]
Subject: Re: ftrace WARNING during boot


* Frederic Weisbecker <[email protected]> wrote:

> On Sat, Oct 03, 2009 at 02:28:50PM +0300, Matti Aarnio wrote:
> > On Sat, Oct 03, 2009 at 01:00:03PM +0200, Frederic Weisbecker wrote:
> > > On Sat, Oct 03, 2009 at 01:53:18PM +0300, Matti Aarnio wrote:
> > > > This is perhaps already fixed, as I have two a bit newer kernels than this one,
> > > > but reporting is better than being silent..
> > >
> > >
> > > Hi,
> > >
> > > Which kernel is this? Does it happen in the current 2.6.32-rc1 ?
> >
> > I do know that reading the trace is difficult, but the asked for information
> > is down in there. Intentionally put there by the kernel-oops coders, I presume.
>
>
> Ah ok. It's just that I'm not that familiar with fedora's kernels naming :-)
>
>
> > I do use vendor kernels, and Fedora 12 beta program has not yet made
> > 2.6.32-rc1 kernel available.
> >
> > However this does not appear in 2.6.31.1-56.fc12.x86_64 kernel that
> > is lattest from vendor, but there I have some other troubles why I
> > took a bit older kernel. (Other troubles with the xfs filesystem
> > lock handling.)
>
> So this looks based on a 2.6.31.1 kernel, more stable. And if it
> doesn't happen with it, then it's fine.
>
> That said, it's all about fedora based kernel so it's a bit hard to
> tell if it came from fedora adds or vanilla kernel code.

Fedora generally doesnt modify any ftrace details.

Ingo

2009-10-03 16:01:22

by Steven Rostedt

[permalink] [raw]
Subject: Re: ftrace WARNING during boot

On Sat, 2009-10-03 at 14:28 +0300, Matti Aarnio wrote:

> > > .....................
> > > kernel: rtc_cmos 00:04: setting system clock to 2009-10-02 23:21:17 UTC (1254525677)
> > > kernel: Initalizing network drop monitor service
> > > kernel: Freeing unused kernel memory: 3196k freed
> > > kernel: NX-protecting the kernel data: ffffffff8150e000, 4469 pages
> > > kernel: Write protecting the kernel read-only data: 7392k
> > > kernel: dracut: dracut-002-2.gitc53acc30.fc12
> > > kernel: udev: starting version 145
> > > kernel: usb 1-5: new high speed USB device using ehci_hcd and address 4
> > > kernel: ------------[ cut here ]------------
> > > kernel: WARNING: at kernel/trace/ftrace.c:1003 ftrace_bug+0x198/0x27e() (Not tainted)
> > > kernel: Hardware name: System Product Name
> > > kernel: Modules linked in: i2c_core(+)
> > > kernel: Pid: 87, comm: modprobe Not tainted 2.6.31-33.fc12.x86_64 #1
> > > kernel: Call Trace:
> > > kernel: [<ffffffff810642ec>] warn_slowpath_common+0x95/0xc3
> > > kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> > > kernel: [<ffffffff81064341>] warn_slowpath_null+0x27/0x3d
> > > kernel: [<ffffffff810d4ace>] ftrace_bug+0x198/0x27e
> > > kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> > > kernel: [<ffffffff810d5d26>] ftrace_convert_nops+0x201/0x2b9
> > > kernel: [<ffffffffa0003072>] ? i2c_new_dummy+0x8/0x5e [i2c_core]
> > > kernel: [<ffffffff810d5e2a>] ftrace_module_notify+0x4c/0x7f
> > > kernel: [<ffffffff81509c65>] notifier_call_chain+0x72/0xba
> > > kernel: [<ffffffff81086e71>] ? __blocking_notifier_call_chain+0x4c/0x8e
> > > kernel: [<ffffffff81086e88>] __blocking_notifier_call_chain+0x63/0x8e
> > > kernel: [<ffffffff81086eda>] blocking_notifier_call_chain+0x27/0x3d
> > > kernel: [<ffffffff810a472a>] sys_init_module+0xb7/0x249
> > > kernel: [<ffffffff81011f42>] system_call_fastpath+0x16/0x1b
> > > kernel: ---[ end trace fbf9054ae0f212c7 ]---
> > > kernel: ftrace faulted on writing [<ffffffffa0003072>] i2c_new_dummy+0x8/0x5e [i2c_core]

This means the update to modify the call to mcount to a nop failed.
Everything else passed (the read and compare). I think I saw some
patches go by that works on making the text in modules read only.

The ftrace update for text in core kernel makes the text writable for
the small window where we call kstop machine and update the text. Then
it makes that code read only again. At the time this code was written,
the modules were always read/write. If this has changed, I believe the
ftrace update needs to be fixed too.

-- Steve


> > > kernel: usb 1-5: New USB device found, idVendor=0424, idProduct=2504
> > > kernel: usb 1-5: New USB device strings: Mfr=0, Product=0, SerialNumber=0
> > > kernel: usb 1-5: configuration #1 chosen from 1 choice
> > > kernel: hub 1-5:1.0: USB hub found
> > > kernel: hub 1-5:1.0: 4 ports detected

2009-10-03 16:37:23

by Matti Aarnio

[permalink] [raw]
Subject: Re: ftrace WARNING during boot

On Sat, Oct 03, 2009 at 11:59:21AM -0400, Steven Rostedt wrote:
> On Sat, 2009-10-03 at 14:28 +0300, Matti Aarnio wrote:
>
....
> > > > kernel: ---[ end trace fbf9054ae0f212c7 ]---
> > > > kernel: ftrace faulted on writing [<ffffffffa0003072>] i2c_new_dummy+0x8/0x5e [i2c_core]
>
> This means the update to modify the call to mcount to a nop failed.
> Everything else passed (the read and compare). I think I saw some
> patches go by that works on making the text in modules read only.
>
> The ftrace update for text in core kernel makes the text writable for
> the small window where we call kstop machine and update the text. Then
> it makes that code read only again. At the time this code was written,
> the modules were always read/write. If this has changed, I believe the
> ftrace update needs to be fixed too.

Lattest kernel on Fedora 12 beta series does not have this trouble.
(It has troubles elsewere, but not at ftrace.)

ACPI: Core revision 20090521
ftrace: converting mcount calls to 0f 1f 44 00 00
ftrace: allocating 21030 entries in 83 pages
Setting APIC routing to flat

> -- Steve

/Matti Aarnio