Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-29 Thread Andy Shevchenko
On Fri, 2017-12-29 at 14:10 +0100, Thomas Gleixner wrote:
> On Fri, 29 Dec 2017, Andy Shevchenko wrote:
> 
> > On Thu, 2017-12-28 at 22:59 +0100, Thomas Gleixner wrote:
> > > On Thu, 28 Dec 2017, Thomas Gleixner wrote:
> > > > On Thu, 28 Dec 2017, Andy Shevchenko wrote:
> > > > > The result w/o above is (full log is available here
> > > > > https://pastebin.com
> > > > > /J5yaTbM9):
> > > > 
> > > > Ok. Which irqs are related to that ISP thingy?
> > > > 
> > > > Are these interrupts MSI?
> > 
> > Yes, they are MSI.
> > 
> > > And looking at the log, I see that you can load the driver
> > > successfully and
> > > the trouble starts afterwards when you actually use it.
> > 
> > Correct.
> > 
> > > Can you please enable CONFIG_GENERIC_IRQ_DEBUGFS and after login,
> > > check
> > > which interrupt is assigned to that atomisp thingy and then
> > > provide
> > > the
> > > output of
> > > 
> > > cat /sys/kernel/debug/irq/irqs/$ATOMISPIRQ
> > 
> > Full log, including output of the above.
> > 
> > https://pastebin.com/4jammqi5
> 
> Thanks for the info. Can you please test the patch below?

Thanks for the patch. It does a trick!

P.S. I noticed that it's combined from at least one that is already in
x86/urgent, so, feel free to add my

Reported-by: Andy Shevchenko 
Tested-by: Andy Shevchenko 

to the rest

> 
> Thanks,
> 
>   tglx
> 
> 8<
> --- a/kernel/irq/msi.c
> +++ b/kernel/irq/msi.c
> @@ -339,6 +339,40 @@ int msi_domain_populate_irqs(struct irq_
>   return ret;
>  }
>  
> +/*
> + * Carefully check whether the device can use reservation mode. If
> + * reservation mode is enabled then the early activation will assign
> a
> + * dummy vector to the device. If the PCI/MSI device does not support
> + * masking of the entry then this can result in spurious interrupts
> when
> + * the device driver is not absolutely careful. But even then a
> malfunction
> + * of the hardware could result in a spurious interrupt on the dummy
> vector
> + * and render the device unusable. If the entry can be masked then
> the core
> + * logic will prevent the spurious interrupt and reservation mode can
> be
> + * used. For now reservation mode is restricted to PCI/MSI.
> + */
> +static bool msi_check_reservation_mode(struct irq_domain *domain,
> +struct msi_domain_info *info,
> +struct device *dev)
> +{
> + struct msi_desc *desc;
> +
> + if (domain->bus_token != DOMAIN_BUS_PCI_MSI)
> + return false;
> +
> + if (!(info->flags & MSI_FLAG_MUST_REACTIVATE))
> + return false;
> +
> + if (IS_ENABLED(CONFIG_PCI_MSI) && pci_msi_ignore_mask)
> + return false;
> +
> + /*
> +  * Checking the first MSI descriptor is sufficient. MSIX
> supports
> +  * masking and MSI does so when the maskbit is set.
> +  */
> + desc = first_msi_entry(dev);
> + return desc->msi_attrib.is_msix || desc->msi_attrib.maskbit;
> +}
> +
>  /**
>   * msi_domain_alloc_irqs - Allocate interrupts from a MSI interrupt
> domain
>   * @domain:  The domain to allocate from
> @@ -353,9 +387,11 @@ int msi_domain_alloc_irqs(struct irq_dom
>  {
>   struct msi_domain_info *info = domain->host_data;
>   struct msi_domain_ops *ops = info->ops;
> - msi_alloc_info_t arg;
> + struct irq_data *irq_data;
>   struct msi_desc *desc;
> + msi_alloc_info_t arg;
>   int i, ret, virq;
> + bool can_reserve;
>  
>   ret = msi_domain_prepare_irqs(domain, dev, nvec, &arg);
>   if (ret)
> @@ -385,6 +421,8 @@ int msi_domain_alloc_irqs(struct irq_dom
>   if (ops->msi_finish)
>   ops->msi_finish(&arg, 0);
>  
> + can_reserve = msi_check_reservation_mode(domain, info, dev);
> +
>   for_each_msi_entry(desc, dev) {
>   virq = desc->irq;
>   if (desc->nvec_used == 1)
> @@ -397,17 +435,28 @@ int msi_domain_alloc_irqs(struct irq_dom
>* the MSI entries before the PCI layer enables MSI
> in the
>* card. Otherwise the card latches a random msi
> message.
>*/
> - if (info->flags & MSI_FLAG_ACTIVATE_EARLY) {
> - struct irq_data *irq_data;
> + if (!(info->flags & MSI_FLAG_ACTIVATE_EARLY))
> + continue;
>  
> + irq_data = irq_domain_get_irq_data(domain, desc-
> >irq);
> + if (!can_reserve)
> + irqd_clr_can_reserve(irq_data);
> + ret = irq_domain_activate_irq(irq_data, can_reserve);
> + if (ret)
> + goto cleanup;
> + }
> +
> + /*
> +  * If these interrupts use reservation mode clear the
> activated bit
> +  * so request_irq() will assign the final vector.
> +  */
> + if (can_reserve) {
> + for_each_msi_entry(desc, dev) {
>   irq_data = irq_domain_get_irq_data(domain,
> desc->irq);
> - ret = i

Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-29 Thread Thomas Gleixner
On Fri, 29 Dec 2017, Andy Shevchenko wrote:

> On Thu, 2017-12-28 at 22:59 +0100, Thomas Gleixner wrote:
> > On Thu, 28 Dec 2017, Thomas Gleixner wrote:
> > > On Thu, 28 Dec 2017, Andy Shevchenko wrote:
> 
> > > > The result w/o above is (full log is available here
> > > > https://pastebin.com
> > > > /J5yaTbM9):
> > > 
> > > Ok. Which irqs are related to that ISP thingy?
> > > 
> > > Are these interrupts MSI?
> 
> Yes, they are MSI.
> 
> > And looking at the log, I see that you can load the driver
> > successfully and
> > the trouble starts afterwards when you actually use it.
> 
> Correct.
> 
> > Can you please enable CONFIG_GENERIC_IRQ_DEBUGFS and after login,
> > check
> > which interrupt is assigned to that atomisp thingy and then provide
> > the
> > output of
> > 
> > cat /sys/kernel/debug/irq/irqs/$ATOMISPIRQ
> 
> Full log, including output of the above.
> 
> https://pastebin.com/4jammqi5

Thanks for the info. Can you please test the patch below?

Thanks,

tglx

8<
--- a/kernel/irq/msi.c
+++ b/kernel/irq/msi.c
@@ -339,6 +339,40 @@ int msi_domain_populate_irqs(struct irq_
return ret;
 }
 
+/*
+ * Carefully check whether the device can use reservation mode. If
+ * reservation mode is enabled then the early activation will assign a
+ * dummy vector to the device. If the PCI/MSI device does not support
+ * masking of the entry then this can result in spurious interrupts when
+ * the device driver is not absolutely careful. But even then a malfunction
+ * of the hardware could result in a spurious interrupt on the dummy vector
+ * and render the device unusable. If the entry can be masked then the core
+ * logic will prevent the spurious interrupt and reservation mode can be
+ * used. For now reservation mode is restricted to PCI/MSI.
+ */
+static bool msi_check_reservation_mode(struct irq_domain *domain,
+  struct msi_domain_info *info,
+  struct device *dev)
+{
+   struct msi_desc *desc;
+
+   if (domain->bus_token != DOMAIN_BUS_PCI_MSI)
+   return false;
+
+   if (!(info->flags & MSI_FLAG_MUST_REACTIVATE))
+   return false;
+
+   if (IS_ENABLED(CONFIG_PCI_MSI) && pci_msi_ignore_mask)
+   return false;
+
+   /*
+* Checking the first MSI descriptor is sufficient. MSIX supports
+* masking and MSI does so when the maskbit is set.
+*/
+   desc = first_msi_entry(dev);
+   return desc->msi_attrib.is_msix || desc->msi_attrib.maskbit;
+}
+
 /**
  * msi_domain_alloc_irqs - Allocate interrupts from a MSI interrupt domain
  * @domain:The domain to allocate from
@@ -353,9 +387,11 @@ int msi_domain_alloc_irqs(struct irq_dom
 {
struct msi_domain_info *info = domain->host_data;
struct msi_domain_ops *ops = info->ops;
-   msi_alloc_info_t arg;
+   struct irq_data *irq_data;
struct msi_desc *desc;
+   msi_alloc_info_t arg;
int i, ret, virq;
+   bool can_reserve;
 
ret = msi_domain_prepare_irqs(domain, dev, nvec, &arg);
if (ret)
@@ -385,6 +421,8 @@ int msi_domain_alloc_irqs(struct irq_dom
if (ops->msi_finish)
ops->msi_finish(&arg, 0);
 
+   can_reserve = msi_check_reservation_mode(domain, info, dev);
+
for_each_msi_entry(desc, dev) {
virq = desc->irq;
if (desc->nvec_used == 1)
@@ -397,17 +435,28 @@ int msi_domain_alloc_irqs(struct irq_dom
 * the MSI entries before the PCI layer enables MSI in the
 * card. Otherwise the card latches a random msi message.
 */
-   if (info->flags & MSI_FLAG_ACTIVATE_EARLY) {
-   struct irq_data *irq_data;
+   if (!(info->flags & MSI_FLAG_ACTIVATE_EARLY))
+   continue;
 
+   irq_data = irq_domain_get_irq_data(domain, desc->irq);
+   if (!can_reserve)
+   irqd_clr_can_reserve(irq_data);
+   ret = irq_domain_activate_irq(irq_data, can_reserve);
+   if (ret)
+   goto cleanup;
+   }
+
+   /*
+* If these interrupts use reservation mode clear the activated bit
+* so request_irq() will assign the final vector.
+*/
+   if (can_reserve) {
+   for_each_msi_entry(desc, dev) {
irq_data = irq_domain_get_irq_data(domain, desc->irq);
-   ret = irq_domain_activate_irq(irq_data, true);
-   if (ret)
-   goto cleanup;
-   if (info->flags & MSI_FLAG_MUST_REACTIVATE)
-   irqd_clr_activated(irq_data);
+   irqd_clr_activated(irq_data);
}
}
+
return 0;
 
 cleanup:
--- a/arch/x86/kernel/apic/vector.c
+++ b/arch/x86/kernel/apic/vector.c
@@ -184,6 +184,7 @@ st

Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-29 Thread Andy Shevchenko
On Thu, 2017-12-28 at 22:59 +0100, Thomas Gleixner wrote:
> On Thu, 28 Dec 2017, Thomas Gleixner wrote:
> > On Thu, 28 Dec 2017, Andy Shevchenko wrote:

> > > The result w/o above is (full log is available here
> > > https://pastebin.com
> > > /J5yaTbM9):
> > 
> > Ok. Which irqs are related to that ISP thingy?
> > 
> > Are these interrupts MSI?

Yes, they are MSI.

> And looking at the log, I see that you can load the driver
> successfully and
> the trouble starts afterwards when you actually use it.

Correct.

> Can you please enable CONFIG_GENERIC_IRQ_DEBUGFS and after login,
> check
> which interrupt is assigned to that atomisp thingy and then provide
> the
> output of
> 
> cat /sys/kernel/debug/irq/irqs/$ATOMISPIRQ

Full log, including output of the above.

https://pastebin.com/4jammqi5

-- 
Andy Shevchenko 
Intel Finland Oy


Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Thomas Gleixner
On Thu, 28 Dec 2017, Thomas Gleixner wrote:
> On Thu, 28 Dec 2017, Andy Shevchenko wrote:
> > On Thu, 2017-12-28 at 21:18 +0100, Thomas Gleixner wrote:
> > > 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.
> 
> Fair enough.
> 
> > The result w/o above is (full log is available here https://pastebin.com
> > /J5yaTbM9):
> 
> Ok. Which irqs are related to that ISP thingy?
> 
> Are these interrupts MSI?

And looking at the log, I see that you can load the driver successfully and
the trouble starts afterwards when you actually use it.

Can you please enable CONFIG_GENERIC_IRQ_DEBUGFS and after login, check
which interrupt is assigned to that atomisp thingy and then provide the
output of

cat /sys/kernel/debug/irq/irqs/$ATOMISPIRQ

Thanks,

tglx


Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Thomas Gleixner
On Thu, 28 Dec 2017, Andy Shevchenko wrote:
> On Thu, 2017-12-28 at 21:18 +0100, Thomas Gleixner wrote:
> > 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.

Fair enough.

> The result w/o above is (full log is available here https://pastebin.com
> /J5yaTbM9):

Ok. Which irqs are related to that ISP thingy?

Are these interrupts MSI?

Thanks,

tglx


Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Andy Shevchenko
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 :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]   -0   0d...0us : vector_clear: irq=1
vector=49 cpu=0 prev_vector=0 prev_cpu=0

[   38.606969]   -0   0d...0us : vector_reserve: irq=1
ret=0

[   38.627799]   -0   0d...0us : vector_config: irq=1
vector=239 cpu=0 apicdest=0x0001

[   38.665139]   -0   00us : vector_setup: irq=1
is_legacy=0 ret=0

[   38.687383]   -0   0d...0us : vector_setup: irq=0
is_legacy=1 ret=0

[   38.709354]   -0   0d...0us : vector_config: irq=0
vector=48 cpu=0 apicdest=0x0001

[   38.746192]   -0   0d...0us : vector_clear: irq=3
vector=51 cpu=0 prev_vector=0 prev_cpu=0

[   38.783535]   -0   0d...0us : vector_reserve: irq=3
ret=0

[   38.804574]   -0   0d...0us : vector_config: irq=3
vector=239 cpu=0 apicdest=0x0001

[   38.842397]   -0   00us : vector_setup: irq=3
is_legacy=0 ret=0

...

so on up to 
[   40.329523]   -0   0d...0us : vector_clear: irq=15
vector=63 cpu=0 prev_vector=0 prev_cpu=0

[   40.372425]   -0   0d...0us : vector_reserve: irq=15
ret=0

[   40.396045]   -0   0d...0us : vector_config: irq=15
vector=239 cpu=0 apicdest=0x0001

[   40.438357]   -0   00us : vector_setup: irq=15
is_legacy=0 ret=0

[   40.463002]   -0   0d...0us : vector_deactivate: irq=0
is_managed=0 can_reserve=0 early=0

[   40.505473]   -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=0x0001

[   40.940771] swapper/-1   0d... 390620us : vector_config: irq=9
vector=33 cpu=0 apicdest=0x0001

...

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=0x0001

[   41.125772] swapper/-1   1 989097us : vector_setup: irq=24
is_legacy=0 ret=0

...

[   48.242842] mdev-14503d.h. 20327793us :
call_function_single_entry: vector=251

[   48.269120] mdev-14503d.h. 20327800us :
call_function_single_exit: vector=251

[   48.295319] modprobe-13480d... 20444228us : vector_activate:
irq=42 is_managed=0 can_reserve=1 early=0

[   48.341248] modprobe-13480d... 20444235us : vector_update: irq=42
vector=52 cpu=0 prev_vector=0 prev_cpu=0

[   48.387914] modprobe-13480d... 20444237us : ve

Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Thomas Gleixner
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 :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'

Thanks,

tglx


Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Andy Shevchenko
On Thu, 2017-12-28 at 21:31 +0200, Andy Shevchenko wrote:

> Anything I missed?

Perhaps I could bisect, though it's not so trivial in this case, when I
have a little more time. I guess it might take up to ~16 steps. If you
can point to more narrow range, it would be great.

-- 
Andy Shevchenko 
Intel Finland Oy


Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Andy Shevchenko
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 :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?

P.S. I didn't apply your previous patch.

> Thanks,
> 
>   tglx
> 
> 8<---
> --- a/arch/x86/kernel/apic/apic.c
> +++ b/arch/x86/kernel/apic/apic.c
> @@ -1978,6 +1978,8 @@ void __init register_lapic_address(unsig
>   /* see sw-dev-man vol 3, chapter 7.4.13.5 */
>   pr_info("spurious APIC interrupt through vector %02x on
> CPU#%d, "
>   "should never happen.\n", vector,
> smp_processor_id());
> + tracing_off();
> + BUG();
>  
>   trace_spurious_apic_exit(vector);
>   exiting_irq();
> 

-- 
Andy Shevchenko 
Intel Finland Oy


Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Thomas Gleixner
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 :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 ...)

Thanks,

tglx

8<---
--- a/arch/x86/kernel/apic/apic.c
+++ b/arch/x86/kernel/apic/apic.c
@@ -1978,6 +1978,8 @@ void __init register_lapic_address(unsig
/* see sw-dev-man vol 3, chapter 7.4.13.5 */
pr_info("spurious APIC interrupt through vector %02x on CPU#%d, "
"should never happen.\n", vector, smp_processor_id());
+   tracing_off();
+   BUG();
 
trace_spurious_apic_exit(vector);
exiting_irq();



Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Andy Shevchenko
On Thu, 2017-12-28 at 18:21 +0100, Thomas Gleixner wrote:
> On Thu, 28 Dec 2017, Shevchenko, Andriy wrote:
> 
> > Hi!
> > 
> > Experimenting with AtomISP (yes, code is ugly and MSI handling
> > rather
> > hackish, though...).
> > 
> > So, with v4.14 base:
> > 
> > [   33.639224] atomisp-isp2 :00:03.0: Start stream on pad 1 for
> > asd0
> > [   33.652355] atomisp-isp2 :00:03.0: irq:0x20
> > [   33.662456] atomisp-isp2 :00:03.0: irq:0x20
> > [   33.698064] atomisp-isp2 :00:03.0: stream[0] started.
> > 
> > Ctrl+C
> > 
> > [   48.185643] atomisp-isp2 :00:03.0:  > [   48.204641] atomisp-isp2 :00:03.0: release device ATOMISP ISP
> > CAPTURE output
> > ...
> > 
> > and machine still alive.
> > 
> > 
> > With v4.15-rc1 base (basically your branch + some my hack patches)
> > the
> > IR
> > Q behaviour changed, i.e. I have got:
> > 
> > 
> > [   85.167061] spurious APIC interrupt through vector ff on CPU#0,
> > should never happen.
> > [   85.199886] atomisp-isp2 :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).

> 
> Thanks,
> 
>   tglx
> 8<-
>  arch/x86/kernel/apic/apic_flat_64.c   |2 +-
>  arch/x86/kernel/apic/probe_32.c   |2 +-
>  arch/x86/kernel/apic/x2apic_cluster.c |2 +-
>  3 files changed, 3 insertions(+), 3 deletions(-)
> 
> --- a/arch/x86/kernel/apic/apic_flat_64.c
> +++ b/arch/x86/kernel/apic/apic_flat_64.c
> @@ -151,7 +151,7 @@ static struct apic apic_flat __ro_after_
>   .apic_id_valid  =
> default_apic_id_valid,
>   .apic_id_registered = flat_apic_id_registered,
>  
> - .irq_delivery_mode  = dest_LowestPrio,
> + .irq_delivery_mode  = dest_Fixed,
>   .irq_dest_mode  = 1, /* logical */
>  
>   .disable_esr= 0,
> --- a/arch/x86/kernel/apic/probe_32.c
> +++ b/arch/x86/kernel/apic/probe_32.c
> @@ -105,7 +105,7 @@ static struct apic apic_default __ro_aft
>   .apic_id_valid  =
> default_apic_id_valid,
>   .apic_id_registered =
> default_apic_id_registered,
>  
> - .irq_delivery_mode  = dest_LowestPrio,
> + .irq_delivery_mode  = dest_Fixed,
>   /* logical delivery broadcast to all CPUs: */
>   .irq_dest_mode  = 1,
>  
> --- a/arch/x86/kernel/apic/x2apic_cluster.c
> +++ b/arch/x86/kernel/apic/x2apic_cluster.c
> @@ -184,7 +184,7 @@ static struct apic apic_x2apic_cluster _
>   .apic_id_valid  = x2apic_apic_id_valid,
>   .apic_id_registered =
> x2apic_apic_id_registered,
>  
> - .irq_delivery_mode  = dest_LowestPrio,
> + .irq_delivery_mode  = dest_Fixed,
>   .irq_dest_mode  = 1, /* logical */
>  
>   .disable_esr= 0,
> 
> 

-- 
Andy Shevchenko 
Intel Finland Oy


Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Andy Shevchenko
On Thu, 2017-12-28 at 19:17 +0200, Andy Shevchenko wrote:
> Hi!
> 
> Experimenting with AtomISP (yes, code is ugly and MSI handling rather
> hackish, though...).
> 
> So, with v4.14 base:

See additional note below.

> 
> [   33.639224] atomisp-isp2 :00:03.0: Start stream on pad 1 for
> asd0
> [   33.652355] atomisp-isp2 :00:03.0: irq:0x20
> [   33.662456] atomisp-isp2 :00:03.0: irq:0x20
> [   33.698064] atomisp-isp2 :00:03.0: stream[0] started.
> 
> Ctrl+C
> 
> [   48.185643] atomisp-isp2 :00:03.0:  [   48.204641] atomisp-isp2 :00:03.0: release device ATOMISP ISP
> CAPTURE output
> ...
> 
> and machine still alive.
> 
> 
> With v4.15-rc1 base (basically your branch + some my hack patches)

Needs a bit of elaboration:
a) nothing had been changed WRT AtomISP driver or media stuff, under
"your branch" one reads Sakari's media_tree.git/atomisp branch;
b) my hack patches has nothing to do with anything except AtomISP
itself;
c) v4.14 base required media/v4.15-1 tag to be merged as well.

>  the IRQ behaviour changed, i.e. I have got:
> 
> 
> [   85.167061] spurious APIC interrupt through vector ff on CPU#0,
> should never happen.
> [   85.199886] atomisp-isp2 :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
> 
> Any comments, Thomas?
> 

-- 
Andy Shevchenko 
Intel Finland Oy


Re: IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Thomas Gleixner
On Thu, 28 Dec 2017, Shevchenko, Andriy wrote:

> Hi!
> 
> Experimenting with AtomISP (yes, code is ugly and MSI handling rather
> hackish, though...).
> 
> So, with v4.14 base:
> 
> [   33.639224] atomisp-isp2 :00:03.0: Start stream on pad 1 for asd0
> [   33.652355] atomisp-isp2 :00:03.0: irq:0x20
> [   33.662456] atomisp-isp2 :00:03.0: irq:0x20
> [   33.698064] atomisp-isp2 :00:03.0: stream[0] started.
> 
> Ctrl+C
> 
> [   48.185643] atomisp-isp2 :00:03.0:  [   48.204641] atomisp-isp2 :00:03.0: release device ATOMISP ISP
> CAPTURE output
> ...
> 
> and machine still alive.
> 
> 
> With v4.15-rc1 base (basically your branch + some my hack patches) the
> IR
> Q behaviour changed, i.e. I have got:
> 
> 
> [   85.167061] spurious APIC interrupt through vector ff on CPU#0,
> should never happen.
> [   85.199886] atomisp-isp2 :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?

Thanks,

tglx
8<-
 arch/x86/kernel/apic/apic_flat_64.c   |2 +-
 arch/x86/kernel/apic/probe_32.c   |2 +-
 arch/x86/kernel/apic/x2apic_cluster.c |2 +-
 3 files changed, 3 insertions(+), 3 deletions(-)

--- a/arch/x86/kernel/apic/apic_flat_64.c
+++ b/arch/x86/kernel/apic/apic_flat_64.c
@@ -151,7 +151,7 @@ static struct apic apic_flat __ro_after_
.apic_id_valid  = default_apic_id_valid,
.apic_id_registered = flat_apic_id_registered,
 
-   .irq_delivery_mode  = dest_LowestPrio,
+   .irq_delivery_mode  = dest_Fixed,
.irq_dest_mode  = 1, /* logical */
 
.disable_esr= 0,
--- a/arch/x86/kernel/apic/probe_32.c
+++ b/arch/x86/kernel/apic/probe_32.c
@@ -105,7 +105,7 @@ static struct apic apic_default __ro_aft
.apic_id_valid  = default_apic_id_valid,
.apic_id_registered = default_apic_id_registered,
 
-   .irq_delivery_mode  = dest_LowestPrio,
+   .irq_delivery_mode  = dest_Fixed,
/* logical delivery broadcast to all CPUs: */
.irq_dest_mode  = 1,
 
--- a/arch/x86/kernel/apic/x2apic_cluster.c
+++ b/arch/x86/kernel/apic/x2apic_cluster.c
@@ -184,7 +184,7 @@ static struct apic apic_x2apic_cluster _
.apic_id_valid  = x2apic_apic_id_valid,
.apic_id_registered = x2apic_apic_id_registered,
 
-   .irq_delivery_mode  = dest_LowestPrio,
+   .irq_delivery_mode  = dest_Fixed,
.irq_dest_mode  = 1, /* logical */
 
.disable_esr= 0,




IRQ behaivour has been changed from v4.14 to v4.15-rc1

2017-12-28 Thread Shevchenko, Andriy
Hi!

Experimenting with AtomISP (yes, code is ugly and MSI handling rather
hackish, though...).

So, with v4.14 base:

[   33.639224] atomisp-isp2 :00:03.0: Start stream on pad 1 for asd0
[   33.652355] atomisp-isp2 :00:03.0: irq:0x20
[   33.662456] atomisp-isp2 :00:03.0: irq:0x20
[   33.698064] atomisp-isp2 :00:03.0: stream[0] started.

Ctrl+C

[   48.185643] atomisp-isp2 :00:03.0: https://lkml.org/lkml/2017/12/22/697

Any comments, Thomas?

-- 
Andy Shevchenko 
Intel Finland Oy - BIC 0357606-4 - Westendinkatu 7, 02160 Espoo