ftrace WARNING during boot

ftrace WARNING during boot

[Matti Aarnio]

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
  ..................

Re: ftrace WARNING during boot

[Frederic Weisbecker]

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 majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

Re: ftrace WARNING during boot

[Matti Aarnio]

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 majordomo@vger.kernel.org
> > 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 majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/

Re: ftrace WARNING during boot

[Frederic Weisbecker]

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.

Re: ftrace WARNING during boot

[Ingo Molnar]

* Frederic Weisbecker <fweisbec@gmail.com> 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

Re: ftrace WARNING during boot

[Steven Rostedt]

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

Re: ftrace WARNING during boot

[Matti Aarnio]

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

Re: ftrace WARNING during boot

[Ingo Molnar]

(Cc:-ed more people)

* Matti Aarnio <matti.aarnio@zmailer.org> 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 majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at  http://www.tux.org/lkml/