Re: IRQ timeout

[John Ogness <john.ogness@linutronix.de>]

On 2009-09-08, Hans-Peter Bock <Hans-Peter.Bock@isw.uni-stuttgart.de> wrote:
>> 2. What are the rt-priorities for your application (including the UIO
>>    thread) and for the network stack threads?
>>    $ ps -Alm
>
> The process "geos" is using the uio_sercos3 driver.
>
> F S   UID   PID  PPID  C PRI  NI ADDR SZ WCHAN  TTY          TIME CMD
...
> 1 -     0     3     2  0   -   - -     0 -      ?        00:00:00 migration/0
> 1 S     0     -     -  0 -40   - -     - migrat -        00:00:00 -
> 5 -     0     4     2  0   -   - -     0 -      ?        00:00:00 sirq-high/0
> 5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
> 5 -     0     5     2  0   -   - -     0 -      ?        00:00:00 sirq-timer/0
> 5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
> 5 -     0     6     2  0   -   - -     0 -      ?        00:00:00 sirq-net-tx/0
> 5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
> 5 -     0     7     2  0   -   - -     0 -      ?        00:00:00 sirq-net-rx/0
> 5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
> 5 -     0     8     2  0   -   - -     0 -      ?        00:00:00 sirq-block/0
> 5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
> 5 -     0     9     2  0   -   - -     0 -      ?        00:00:00 sirq-tasklet/0
> 5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
> 5 -     0    10     2  0   -   - -     0 -      ?        00:00:00 sirq-sched/0
> 5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
> 5 -     0    11     2  0   -   - -     0 -      ?        00:00:00 sirq-hrtimer/0
> 5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
> 5 -     0    12     2  0   -   - -     0 -      ?        00:00:00 sirq-rcu/0
> 5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
> 1 -     0    13     2  0   -   - -     0 -      ?        00:00:00 posixcputmr/0
> 1 S     0     -     -  0 -40   - -     - posix_ -        00:00:00 -
> 5 -     0    14     2  0   -   - -     0 -      ?        00:00:00 watchdog/0
> 5 S     0     -     -  0 -40   - -     - watchd -        00:00:00 -
...
> 7 -     0  1576     2  0   -   - -     0 -      ?        00:00:00 IRQ-17
> 7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
...
> 7 -     0  2196     2  0   -   - -     0 -      ?        00:00:00 IRQ-16
> 7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
...
> 4 -     0  2229  2212  0   -   - - 22379 -      pts/0    00:00:00 geos
> 4 S     0     -     -  0 -40   - -     - futex_ -        00:00:00 -
> 5 S     0     -     -  0 -30   - -     - uio_re -        00:00:00 -

Your network stack threads have a priority of 49. The network interrupt
thread (IRQ-17) has a priority of 50. The sercos interrupt thread
(IRQ-16) also has a priority of 50. Your geos UIO thread has a priority
of 89. And another geos thread (most likely the one executing the main
sercos driver logic) has the highest priority possible: 99!

I don't know exactly what your geos threads are doing, but I suspect
that they are the cause. Try reducing the priority of the non-UIO
application thread. I do not know why it should have a higher priority
than the UIO thread. (Is there ever a reason to run an application at
the same priority as such important processes as the watchdog?)

If reducing the priority below that of the UIO thread does not help,
consider reducing the priority below that of the network stack
(<49). If your application is more important that any network activity,
then you would not want to do this. But for now it would be helpful to
identify if the non-UIO thread is really at fault here.

>> 3. How many interrupts per second (approx.) are being generated by
>>    the Sercos hardware while your application is running?
>>    $ cat /proc/interrupts; sleep 1; cat /proc/interrupts
>
> The SERCOS III master runs a cycle time of 2ms, that should be 500
> interrupts per second:
>
>            CPU0       CPU1       
>  16:      26948          0   IO-APIC-fasteoi   Sercos_III_PCI
> LOC:     129961      98461   Local timer interrupts
>
>            CPU0       CPU1       
>  16:      27448          0   IO-APIC-fasteoi   Sercos_III_PCI
> LOC:     130597      99473   Local timer interrupts

Indeed. There are also over 500 timer interrupts per second, so I assume
that your non-UIO geos thread is using a 2ms timer to perform the sercos
driver duties.

>> 4. What is the system load while your application is running and when
>>    the network stops working?
>>    $ cat /proc/loadavg
>
> The system is idle:
>
> 0.01 0.02 0.00 1/114 2374

Was this after the application was running for a few minutes? This
surprises me because the reported error implies that the network isn't
getting properly scheduled.

John Ogness