[Xenomai] IRQ155 not handled. Disabling IRQ line

[Xenomai] IRQ155 not handled. Disabling IRQ line

[Terje Frøysa]

Dear forum,

Question:
If a driver is deemed buggy and the IRQ disabled, why is it still serving the interrupts?

Running Debian 3.8.13-bone67 and Xenomai 2.6.4

At opening call, my GPIO RTDM IRQ driver enables a GPIO line w/irq.
My user-space program issues read-requests to receive a time-stamp for each irq.
The irq handler is very compact. It only reads the system time, rises a semaphore if not already up and returns RT_INTR_HANDLED.

When starting (open + loop w/reads),  the dmesg log-message appears:  "IRQ155 not handled. Disabling IRQ line".
It appears only once in the start.
Never-the-less, the interrupts are still handled and keep coming.

Regards
Terje Froysa

Dmesg log:
[10745.676319] RTDM IMU pin 27 - irq number 155
[10745.676326] RTDM IMU 27 - request GPIO
[10745.676345] RTDM IMU 27 - request IRQ 155
[10745.676369] RTDM IMU 27 - set IRQ type RISING_EDGE
[10745.676384] RTDM IMU 27 - init semaphore
[10745.676395] RTDM IMU 27 - enable IRQ
[10750.680486] Xenomai: xnintr_irq_handler: IRQ155 not handled. Disabling IRQ line.
:
200000 irqs handled, nothing logged.
:
[11745.698291] RTDM IMU 27 - close

Smail: Terje Frøysa, SINTEF ICT (Information and Communication Technology), N-7465 Trondheim, Norway.
Email: terje.froysa@sintef.no<blocked::mailto:terje.froysa@sintef.no> <mailto:terje.froysa@sintef.no<blocked::mailto:terje.froysa@sintef.no>>
Phone: +47 930 03603,
Company: Independent R&D, see <http://www.sintef.no/<blocked::http://www.sintef.no/>

Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

[Gilles Chanteperdrix]

On Tue, Dec 02, 2014 at 09:28:37AM +0000, Terje Frøysa wrote:
> Dear forum,
> 
> Question:
> If a driver is deemed buggy and the IRQ disabled, why is it still serving the interrupts?
> 
> Running Debian 3.8.13-bone67 and Xenomai 2.6.4
> 
> At opening call, my GPIO RTDM IRQ driver enables a GPIO line w/irq.
> My user-space program issues read-requests to receive a time-stamp for each irq.
> The irq handler is very compact. It only reads the system time, rises a semaphore if not already up and returns RT_INTR_HANDLED.
> 
> When starting (open + loop w/reads),  the dmesg log-message appears:  "IRQ155 not handled. Disabling IRQ line".
> It appears only once in the start.
> Never-the-less, the interrupts are still handled and keep coming.

Well, probably because the code re-enables the irq line ?

-- 
					    Gilles.

Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

[Terje Frøysa]

Well, the code:
	DEBUG_PRINT(KERN_DEBUG "RTDM IMU %d - enable IRQ\n", info->gpio_pin_n);
	err = rtdm_irq_enable(&info->gpio_irq);
only exists one place in the driver and is only executed in the kernel-context of  rt_dev_open() from user-space.
The irq-device is opened only once before entering the read-loop.

The repeated read calls from the user space (rt_dev_read()) only blocs on the irq semaphore and copies the irq-time back to the user.
I don't see how the irq-line can be re-enabled by this code.
If the device have been repeatedly opened, the dmesg would have been flooded with log-messages.

Terje

-----Original Message-----
From: Gilles Chanteperdrix [mailto:gilles.chanteperdrix@xenomai.org] 
Sent: 2. desember 2014 10:34
To: Terje Frøysa
Cc: xenomai@xenomai.org
Subject: Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

On Tue, Dec 02, 2014 at 09:28:37AM +0000, Terje Frøysa wrote:
> Dear forum,
> 
> Question:
> If a driver is deemed buggy and the IRQ disabled, why is it still serving the interrupts?
> 
> Running Debian 3.8.13-bone67 and Xenomai 2.6.4
> 
> At opening call, my GPIO RTDM IRQ driver enables a GPIO line w/irq.
> My user-space program issues read-requests to receive a time-stamp for each irq.
> The irq handler is very compact. It only reads the system time, rises a semaphore if not already up and returns RT_INTR_HANDLED.
> 
> When starting (open + loop w/reads),  the dmesg log-message appears:  "IRQ155 not handled. Disabling IRQ line".
> It appears only once in the start.
> Never-the-less, the interrupts are still handled and keep coming.

Well, probably because the code re-enables the irq line ?

-- 
					    Gilles.

Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

[Gilles Chanteperdrix]

On Tue, Dec 02, 2014 at 09:51:01AM +0000, Terje Frøysa wrote:
> Well, the code:
> 	DEBUG_PRINT(KERN_DEBUG "RTDM IMU %d - enable IRQ\n", info->gpio_pin_n);
> 	err = rtdm_irq_enable(&info->gpio_irq);
> only exists one place in the driver and is only executed in the kernel-context of  rt_dev_open() from user-space.
> The irq-device is opened only once before entering the read-loop.
> 
> The repeated read calls from the user space (rt_dev_read()) only blocs on the irq semaphore and copies the irq-time back to the user.
> I don't see how the irq-line can be re-enabled by this code.
> If the device have been repeatedly opened, the dmesg would have been flooded with log-messages.

What flags do you pass to rtdm_irq_request?

-- 
					    Gilles.

Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

[Terje Frøysa]

Thanks Gilles,

The flags are zero (from example code).... should I have used RTDM_IRQTYPE_EDGE ?

err = rtdm_irq_request(&info->gpio_irq, gpio_irq_n, imu_irq_handler, 0, THIS_MODULE->name,  NULL);

Terje

-----Original Message-----
From: Gilles Chanteperdrix [mailto:gilles.chanteperdrix@xenomai.org] 
Sent: 2. desember 2014 10:57
To: Terje Frøysa
Cc: xenomai@xenomai.org
Subject: Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

On Tue, Dec 02, 2014 at 09:51:01AM +0000, Terje Frøysa wrote:
> Well, the code:
> 	DEBUG_PRINT(KERN_DEBUG "RTDM IMU %d - enable IRQ\n", info->gpio_pin_n);
> 	err = rtdm_irq_enable(&info->gpio_irq); only exists one place in the 
> driver and is only executed in the kernel-context of  rt_dev_open() from user-space.
> The irq-device is opened only once before entering the read-loop.
> 
> The repeated read calls from the user space (rt_dev_read()) only blocs on the irq semaphore and copies the irq-time back to the user.
> I don't see how the irq-line can be re-enabled by this code.
> If the device have been repeatedly opened, the dmesg would have been flooded with log-messages.

What flags do you pass to rtdm_irq_request?

-- 
					    Gilles.

Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

[Gilles Chanteperdrix]

On Tue, Dec 02, 2014 at 10:20:59AM +0000, Terje Frøysa wrote:
> Thanks Gilles,
> 
> The flags are zero (from example code).... should I have used RTDM_IRQTYPE_EDGE ?
> 
> err = rtdm_irq_request(&info->gpio_irq, gpio_irq_n, imu_irq_handler, 0, THIS_MODULE->name,  NULL);

If the IRQ is of a certain type, you certainly want to pass the
right irq type.

Looking at the code:
- you only get the message after not returning RTDM_IRQ_HANDLED 1000
times, so, if you see the message, it is sure that some code is not
returning RTDM_IRQ_HANDLED, I suggest you check if the interrupt is
shared, and if another handler is not called
- the xenomai core skips reenabling the interrupts in that case, so,
if it gets reenabled, something re-enables it.

Are you sure that you do not register the handler to early, that it
fires because the hardware is not initialized, then gets disabled by
Xenomai core. Then later, your driver performs the hardware
initializations, and re-enables irqs ?

-- 
					    Gilles.

Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

[Terje Frøysa]

Thanks Gilles,

I think setting the IRQ type mended the problem.

Before that I did some digging:
I couldn't find any information that indicated a shared interrupt:
The /proc/interrupts did not contain the IRQ155 and the /proc/xenomai/irq held only one entry for my driver (below).
The external interrupt source is a PWM generated pulse-train of 200Hz, i.e. 5ms interval started the code-line before entering the read-loop.
You say that the line must have been unserved for a 1000 events before being disabled.
A 1000 events from when and at what rate if EDGE not spesified? The irq handler have no optional returns but "RT_INTR_HANDLED".
Hence, I cannot imagine where the non-handled returns are coming from. At 5ms rate this would require 5s of pulses to reach 1000.
The distance in time from IRQ enable to disable the IRQ line seem less than 4us..
[19833.958667] RTDM IMU 27 - enable IRQ
[19838.962472] Xenomai: xnintr_irq_handler: IRQ155 not handled. Disabling IRQ line.

However, I changed the flags to "RTDM_IRQTYPE_EDGE" and it seemed to have a good effect.
I don't get the message any longer 

Best regards
Terje

[  731.849026] RTDM IMU INT (GPIO 27) - open
[  731.849047] RTDM IMU pin 27 - irq number 155
[  731.849054] RTDM IMU 27 - request GPIO
[  731.849073] RTDM IMU 27 - request IRQ 155
[  731.849097] RTDM IMU 27 - set IRQ type RISING_EDGE
[  731.849112] RTDM IMU 27 - init semaphore
[  731.849122] RTDM IMU 27 - enable IRQ


/proc/xenomai/irq :
IRQ         CPU0
 67:      495238         [timer]
155:      298510         imu_rtdm
1031:           0         [sync]
1032:           0         [timer-ipi]
1033:           0         [reschedule]
1034:           0         [virtual]
1038:      298252         [virtual]

-----Original Message-----
From: Gilles Chanteperdrix [mailto:gilles.chanteperdrix@xenomai.org] 
Sent: 2. desember 2014 11:54
To: Terje Frøysa
Cc: xenomai@xenomai.org
Subject: Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

On Tue, Dec 02, 2014 at 10:20:59AM +0000, Terje Frøysa wrote:
> Thanks Gilles,
> 
> The flags are zero (from example code).... should I have used RTDM_IRQTYPE_EDGE ?
> 
> err = rtdm_irq_request(&info->gpio_irq, gpio_irq_n, imu_irq_handler, 
> 0, THIS_MODULE->name,  NULL);

If the IRQ is of a certain type, you certainly want to pass the right irq type.

Looking at the code:
- you only get the message after not returning RTDM_IRQ_HANDLED 1000 times, so, if you see the message, it is sure that some code is not returning RTDM_IRQ_HANDLED, I suggest you check if the interrupt is shared, and if another handler is not called
- the xenomai core skips reenabling the interrupts in that case, so, if it gets reenabled, something re-enables it.

Are you sure that you do not register the handler to early, that it fires because the hardware is not initialized, then gets disabled by Xenomai core. Then later, your driver performs the hardware initializations, and re-enables irqs ?

-- 
					    Gilles.

Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

[Gilles Chanteperdrix]

On Tue, Dec 02, 2014 at 12:07:50PM +0000, Terje Frøysa wrote:
> Thanks Gilles,
> 
> I think setting the IRQ type mended the problem.
> 
> Before that I did some digging:
> I couldn't find any information that indicated a shared interrupt:
> The /proc/interrupts did not contain the IRQ155 and the /proc/xenomai/irq held only one entry for my driver (below).
> The external interrupt source is a PWM generated pulse-train of 200Hz, i.e. 5ms interval started the code-line before entering the read-loop.
> You say that the line must have been unserved for a 1000 events before being disabled.
> A 1000 events from when and at what rate if EDGE not spesified? The irq handler have no optional returns but "RT_INTR_HANDLED".
> Hence, I cannot imagine where the non-handled returns are coming from. At 5ms rate this would require 5s of pulses to reach 1000.
> The distance in time from IRQ enable to disable the IRQ line seem less than 4us..
> [19833.958667] RTDM IMU 27 - enable IRQ
> [19838.962472] Xenomai: xnintr_irq_handler: IRQ155 not handled. Disabling IRQ line.
> 
> However, I changed the flags to "RTDM_IRQTYPE_EDGE" and it seemed to have a good effect.
> I don't get the message any longer 

If the default irq type is say level low, your pwm signal being low
for for instance 5ms generates interrupts during 5ms, and since the
interrupt condition (low level) is still true, the interrupt
triggers over and over again.

Is the interrupt shared with Linux ?

-- 
					    Gilles.

Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

[Terje Frøysa]

No, not as far as I can tell.
I have tried to find out how to tell. The only clue I get from the web is to check the 
/proc/interrupts
/proc/xenomai/irq
The interrupt exists only once in the /proc/xenomai/irq.

Are there other means to check this?

Best regards
Terje

-----Original Message-----
From: Gilles Chanteperdrix [mailto:gilles.chanteperdrix@xenomai.org] 
Sent: 2. desember 2014 13:13
To: Terje Frøysa
Cc: xenomai@xenomai.org
Subject: Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

On Tue, Dec 02, 2014 at 12:07:50PM +0000, Terje Frøysa wrote:
> Thanks Gilles,
> 
> I think setting the IRQ type mended the problem.
> 
> Before that I did some digging:
> I couldn't find any information that indicated a shared interrupt:
> The /proc/interrupts did not contain the IRQ155 and the /proc/xenomai/irq held only one entry for my driver (below).
> The external interrupt source is a PWM generated pulse-train of 200Hz, i.e. 5ms interval started the code-line before entering the read-loop.
> You say that the line must have been unserved for a 1000 events before being disabled.
> A 1000 events from when and at what rate if EDGE not spesified? The irq handler have no optional returns but "RT_INTR_HANDLED".
> Hence, I cannot imagine where the non-handled returns are coming from. At 5ms rate this would require 5s of pulses to reach 1000.
> The distance in time from IRQ enable to disable the IRQ line seem less than 4us..
> [19833.958667] RTDM IMU 27 - enable IRQ [19838.962472] Xenomai: 
> xnintr_irq_handler: IRQ155 not handled. Disabling IRQ line.
> 
> However, I changed the flags to "RTDM_IRQTYPE_EDGE" and it seemed to have a good effect.
> I don't get the message any longer

If the default irq type is say level low, your pwm signal being low for for instance 5ms generates interrupts during 5ms, and since the interrupt condition (low level) is still true, the interrupt triggers over and over again.

Is the interrupt shared with Linux ?

-- 
					    Gilles.

Re: [Xenomai] IRQ155 not handled. Disabling IRQ line

[Gilles Chanteperdrix]

On Tue, Dec 02, 2014 at 12:16:08PM +0000, Terje Frøysa wrote:
> No, not as far as I can tell.
> I have tried to find out how to tell. The only clue I get from the web is to check the 
> /proc/interrupts
> /proc/xenomai/irq
> The interrupt exists only once in the /proc/xenomai/irq.
> 
> Are there other means to check this?

That is the way, yes.

Could you post the code of the irq handler you pass to
rtdm_irq_request ?

-- 
					    Gilles.