From: Andy Shevchenko <andriy.shevchenko@linux.intel.com>
To: Thomas Gleixner <tglx@linutronix.de>
Cc: "alan@linux.intel.com" <alan@linux.intel.com>,
"Ailus, Sakari" <sakari.ailus@intel.com>,
"linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>,
"linux-media@vger.kernel.org" <linux-media@vger.kernel.org>
Subject: Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1
Date: Thu, 28 Dec 2017 23:03:45 +0200 [thread overview]
Message-ID: <1514495025.7000.484.camel@linux.intel.com> (raw)
In-Reply-To: <alpine.DEB.2.20.1712282117160.1899@nanos>
On Thu, 2017-12-28 at 21:18 +0100, Thomas Gleixner wrote:
> On Thu, 28 Dec 2017, Andy Shevchenko wrote:
> > On Thu, 2017-12-28 at 18:44 +0100, Thomas Gleixner wrote:
> > > On Thu, 28 Dec 2017, Andy Shevchenko wrote:
> > > > On Thu, 2017-12-28 at 18:21 +0100, Thomas Gleixner wrote:
> > > > > > [ 85.167061] spurious APIC interrupt through vector ff on
> > > > > > CPU#0,
> > > > > > should never happen.
> > > > > > [ 85.199886] atomisp-isp2 0000:00:03.0: stream[0] started.
> > > > > >
> > > > > > and Ctrl+C does NOT work. Machine just hangs.
> > > > > >
> > > > > > It might be related to this:
> > > > > > https://lkml.org/lkml/2017/12/22/697
> > > > >
> > > > > I don't think so.
> > > > >
> > > > > Does the patch below cure it?
> > > >
> > > > Unfortunately, no.
> > > >
> > > > Same behaviour.
> > > >
> > > > Tell me if I need to provide some debug before it hangs. For now
> > > > I
> > > > have
> > > > apic=debug (AFAIR it doesn't affect this).
> > >
> > > The interesting question is why that spurious APIC interrupt
> > > through
> > > vector
> > > ff happens. Can you please add the following to the kernel command
> > > line:
> > >
> > > 'trace_events=irq_vectors:* ftrace_dump_on_oops'
> > >
> > > and apply the patch below. That should spill out the trace over
> > > serial
> > > (I
> > > hope you have that ...)
> >
> > With or without CONFIG_FUNCTION_TRACER=y I have got
> >
> >
> > [ 28.977918] Dumping ftrace buffer:
> > [ 28.988115] (ftrace buffer empty)
> >
> > followed by BUG() output.
> >
> > ...
> > [ 28.930154] RIP: 0010:smp_spurious_interrupt+0x67/0xb0
> > ...
> >
> >
> > Anything I missed?
>
> Yes, you missed the typo in the command line. It should be:
>
> 'trace_event=irq_vectors:* ftrace_dump_on_oops'
Indeed.
So, I had to disable LOCAL_TIMER_VECTOR, CALL_FUNCTION_VECTOR and
RESCHDULE_VECTOR tracing, otherwise I got a lot of spam and RCU stalls.
The result w/o above is (full log is available here https://pastebin.com
/J5yaTbM9):
[ 38.570130] <idle>-0 0d... 0us : vector_clear: irq=1
vector=49 cpu=0 prev_vector=0 prev_cpu=0
[ 38.606969] <idle>-0 0d... 0us : vector_reserve: irq=1
ret=0
[ 38.627799] <idle>-0 0d... 0us : vector_config: irq=1
vector=239 cpu=0 apicdest=0x00000001
[ 38.665139] <idle>-0 0.... 0us : vector_setup: irq=1
is_legacy=0 ret=0
[ 38.687383] <idle>-0 0d... 0us : vector_setup: irq=0
is_legacy=1 ret=0
[ 38.709354] <idle>-0 0d... 0us : vector_config: irq=0
vector=48 cpu=0 apicdest=0x00000001
[ 38.746192] <idle>-0 0d... 0us : vector_clear: irq=3
vector=51 cpu=0 prev_vector=0 prev_cpu=0
[ 38.783535] <idle>-0 0d... 0us : vector_reserve: irq=3
ret=0
[ 38.804574] <idle>-0 0d... 0us : vector_config: irq=3
vector=239 cpu=0 apicdest=0x00000001
[ 38.842397] <idle>-0 0.... 0us : vector_setup: irq=3
is_legacy=0 ret=0
...
so on up to
[ 40.329523] <idle>-0 0d... 0us : vector_clear: irq=15
vector=63 cpu=0 prev_vector=0 prev_cpu=0
[ 40.372425] <idle>-0 0d... 0us : vector_reserve: irq=15
ret=0
[ 40.396045] <idle>-0 0d... 0us : vector_config: irq=15
vector=239 cpu=0 apicdest=0x00000001
[ 40.438357] <idle>-0 0.... 0us : vector_setup: irq=15
is_legacy=0 ret=0
[ 40.463002] <idle>-0 0d... 0us : vector_deactivate: irq=0
is_managed=0 can_reserve=0 early=0
[ 40.505473] <idle>-0 0d... 0us : vector_activate: irq=0
is_managed=0 can_reserve=0 early=0
Then several times (for different tasks)
[ 40.548017] kauditd-32 0d.h. 307277us :
call_function_single_entry: vector=251
[ 40.572984] kauditd-32 0dNh. 307281us :
call_function_single_exit: vector=251
...
[ 40.792078] swapper/-1 0d... 390605us : vector_activate: irq=9
is_managed=0 can_reserve=1 early=0
[ 40.832953] swapper/-1 0d... 390611us : vector_update: irq=9
vector=33 cpu=0 prev_vector=0 prev_cpu=0
[ 40.874548] swapper/-1 0d... 390613us : vector_alloc: irq=9
vector=33 reserved=1 ret=0
[ 40.899551] swapper/-1 0d... 390614us : vector_config: irq=9
vector=33 cpu=0 apicdest=0x00000001
[ 40.940771] swapper/-1 0d... 390620us : vector_config: irq=9
vector=33 cpu=0 apicdest=0x00000001
...
For irq=24-29, 47, 49:
[ 41.071806] swapper/-1 1d... 989092us : vector_reserve: irq=24
ret=0
[ 41.088297] swapper/-1 1d... 989096us : vector_config: irq=24
vector=239 cpu=0 apicdest=0x00000001
[ 41.125772] swapper/-1 1.... 989097us : vector_setup: irq=24
is_legacy=0 ret=0
...
[ 48.242842] mdev-1450 3d.h. 20327793us :
call_function_single_entry: vector=251
[ 48.269120] mdev-1450 3d.h. 20327800us :
call_function_single_exit: vector=251
[ 48.295319] modprobe-1348 0d... 20444228us : vector_activate:
irq=42 is_managed=0 can_reserve=1 early=0
[ 48.341248] modprobe-1348 0d... 20444235us : vector_update: irq=42
vector=52 cpu=0 prev_vector=0 prev_cpu=0
[ 48.387914] modprobe-1348 0d... 20444237us : vector_alloc: irq=42
vector=52 reserved=1 ret=0
[ 48.415547] modprobe-1348 0d... 20444238us : vector_config: irq=42
vector=52 cpu=0 apicdest=0x00000001
[ 48.461465] modprobe-1348 0d... 20444243us : vector_config: irq=42
vector=52 cpu=0 apicdest=0x00000001
[ 48.507688] modprobe-1348 0d... 20484235us : vector_activate:
irq=43 is_managed=0 can_reserve=1 early=0
[ 48.554044] modprobe-1348 0d... 20484241us : vector_update: irq=43
vector=53 cpu=0 prev_vector=0 prev_cpu=0
[ 48.600812] modprobe-1348 0d... 20484243us : vector_alloc: irq=43
vector=53 reserved=1 ret=0
[ 48.628494] modprobe-1348 0d... 20484244us : vector_config: irq=43
vector=53 cpu=0 apicdest=0x00000001
[ 48.674508] modprobe-1348 0d... 20484248us : vector_config: irq=43
vector=53 cpu=0 apicdest=0x00000001
[ 48.720830] <idle>-0 1d.h. 20591763us :
call_function_single_entry: vector=251
[ 48.747573] <idle>-0 1d.h. 20591768us :
call_function_single_exit: vector=251
[ 48.774025] modprobe-1348 1d... 20831415us : vector_reserve:
irq=150 ret=0
[ 48.799631] modprobe-1348 1d... 20831419us : vector_config:
irq=150 vector=239 cpu=0 apicdest=0x00000001
[ 48.845791] modprobe-1348 1.... 20831420us : vector_setup: irq=150
is_legacy=0 ret=0
[ 48.872515] modprobe-1348 1.... 20831427us : vector_activate:
irq=150 is_managed=0 can_reserve=1 early=1
[ 48.918432] modprobe-1348 1d... 20831428us : vector_config:
irq=150 vector=239 cpu=0 apicdest=0x00000001
[ 48.964534] modprobe-1348 1d... 21152409us : vector_activate:
irq=150 is_managed=0 can_reserve=1 early=0
[ 49.010805] modprobe-1348 1d... 21152415us : vector_update:
irq=150 vector=54 cpu=0 prev_vector=0 prev_cpu=0
[ 49.057553] modprobe-1348 1d... 21152417us : vector_alloc: irq=150
vector=54 reserved=1 ret=0
[ 49.085503] modprobe-1348 1d... 21152418us : vector_config:
irq=150 vector=54 cpu=0 apicdest=0x00000001
[ 49.132545] modprobe-1348 1d... 21152428us : vector_config:
irq=150 vector=54 cpu=0 apicdest=0x00000001
[ 49.180426] <idle>-0 2d.h. 21227397us :
call_function_single_entry: vector=251
[ 49.208066] <idle>-0 2d.h. 21227403us :
call_function_single_exit: vector=251
[ 49.235397] <idle>-0 3d.h. 21229548us :
call_function_single_entry: vector=251
[ 49.262625] <idle>-0 3d.h. 21229551us :
call_function_single_exit: vector=251
[ 49.289544] <idle>-0 0d.h. 21231514us :
call_function_single_entry: vector=251
[ 49.316365] <idle>-0 0d.h. 21231519us :
call_function_single_exit: vector=251
[ 49.343015] <idle>-0 1d.h. 21238805us :
call_function_single_entry: vector=251
[ 49.369550] <idle>-0 1d.h. 21238809us :
call_function_single_exit: vector=251
[ 49.395774] <idle>-0 3d.h. 24735137us :
call_function_single_entry: vector=251
[ 49.421902] <idle>-0 3d.h. 24735143us :
call_function_single_exit: vector=251
[ 49.447720] <idle>-0 0d.h. 38913766us : spurious_apic_entry:
vector=255
--
Andy Shevchenko <andriy.shevchenko@linux.intel.com>
Intel Finland Oy
next prev parent reply other threads:[~2017-12-28 21:05 UTC|newest]
Thread overview: 62+ messages / expand[flat|nested] mbox.gz Atom feed top
2017-12-28 17:17 IRQ behaivour has been changed from v4.14 to v4.15-rc1 Shevchenko, Andriy
2017-12-28 17:21 ` Thomas Gleixner
2017-12-28 17:34 ` Andy Shevchenko
2017-12-28 17:44 ` Thomas Gleixner
2017-12-28 19:31 ` Andy Shevchenko
2017-12-28 19:36 ` Andy Shevchenko
2017-12-28 20:18 ` Thomas Gleixner
2017-12-28 21:03 ` Andy Shevchenko [this message]
2017-12-28 21:31 ` Thomas Gleixner
2017-12-28 21:59 ` Thomas Gleixner
2017-12-29 12:06 ` Andy Shevchenko
2017-12-29 13:10 ` Thomas Gleixner
2017-12-29 14:27 ` Andy Shevchenko
2017-12-29 20:20 ` [tip:irq/urgent] genirq/msi, x86/vector: Prevent reservation mode for non maskable MSI tip-bot for Thomas Gleixner
2017-12-28 17:23 ` IRQ behaivour has been changed from v4.14 to v4.15-rc1 Andy Shevchenko
[not found] <20171218082011.GA24638@arch-chirva.localdomain>
2017-12-18 10:11 ` PROBLEM: 4.15.0-rc3 APIC causes lockups on Core 2 Duo laptop Pavel Machek
2017-12-19 8:34 ` Alexandru Chirvasitu
2017-12-20 0:31 ` Thomas Gleixner
2017-12-20 3:58 ` Dou Liyang
2017-12-20 13:19 ` Alexandru Chirvasitu
2017-12-20 19:45 ` Alexandru Chirvasitu
2017-12-21 2:23 ` Alexandru Chirvasitu
2017-12-22 10:28 ` Dou Liyang
[not found] ` <20171222142053.3cbhi2nhh24w7yoo@D-69-91-141-110.dhcp4.washington.edu>
2017-12-22 21:31 ` Dexuan Cui
[not found] ` <20171222222917.GA1138@arch-chirva.localdomain>
2017-12-23 1:35 ` Dexuan Cui
2017-12-23 4:51 ` Alexandru Chirvasitu
2017-12-23 13:32 ` Thomas Gleixner
2017-12-23 20:01 ` Alexandru Chirvasitu
2017-12-27 8:14 ` Dou Liyang
2017-12-27 16:18 ` Alexandru Chirvasitu
[not found] ` <20171227195007.GF1410@arch-chirva.localdomain>
2017-12-27 23:13 ` Alexandru Chirvasitu
2017-12-28 2:06 ` Dou Liyang
2017-12-28 2:51 ` Alexandru Chirvasitu
2017-12-28 10:23 ` Dou Liyang
2017-12-24 3:29 ` Dou Liyang
2017-12-28 11:00 ` Thomas Gleixner
2017-12-28 14:21 ` Alexandru Chirvasitu
2017-12-28 14:48 ` Thomas Gleixner
2017-12-28 15:48 ` Alexandru Chirvasitu
2017-12-28 16:05 ` Alexandru Chirvasitu
2017-12-28 16:10 ` Thomas Gleixner
2017-12-28 17:22 ` Alexandru Chirvasitu
2017-12-28 17:29 ` Thomas Gleixner
2017-12-28 17:50 ` Alexandru Chirvasitu
2017-12-28 18:32 ` Thomas Gleixner
2017-12-28 21:54 ` Thomas Gleixner
2017-12-28 22:50 ` Alexandru Chirvasitu
2017-12-28 22:57 ` Thomas Gleixner
2017-12-28 23:19 ` Thomas Gleixner
2017-12-28 23:30 ` Alexandru Chirvasitu
2017-12-28 23:36 ` Thomas Gleixner
2017-12-28 23:59 ` Alexandru Chirvasitu
2017-12-29 8:07 ` Thomas Gleixner
2017-12-29 11:49 ` Alexandru Chirvasitu
2017-12-29 12:22 ` Alexandru Chirvasitu
2017-12-29 13:09 ` Thomas Gleixner
2017-12-29 14:06 ` Alexandru Chirvasitu
2017-12-29 0:15 ` Bjorn Helgaas
2017-12-29 0:38 ` Alexandru Chirvasitu
2017-12-28 11:03 ` Thomas Gleixner
2017-12-28 19:01 ` Dexuan Cui
2017-12-28 20:14 ` Thomas Gleixner
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=1514495025.7000.484.camel@linux.intel.com \
--to=andriy.shevchenko@linux.intel.com \
--cc=alan@linux.intel.com \
--cc=linux-kernel@vger.kernel.org \
--cc=linux-media@vger.kernel.org \
--cc=sakari.ailus@intel.com \
--cc=tglx@linutronix.de \
/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;
as well as URLs for NNTP newsgroup(s).