public inbox for linux-rt-users@vger.kernel.org
 help / color / mirror / Atom feed
* IRQ timeout
@ 2009-09-08 12:26 Hans-Peter Bock
  2009-09-08 13:53 ` John Ogness
  0 siblings, 1 reply; 6+ messages in thread
From: Hans-Peter Bock @ 2009-09-08 12:26 UTC (permalink / raw)
  To: linux-rt-users; +Cc: john.ogness

[-- Attachment #1: Type: text/plain, Size: 2322 bytes --]

Hello,

when I start my application using the uio_sercos3 driver, the network on my e100 stops working after a short time. Some miutes later I got this message in the console and my network started working again:

[  725.000141] ------------[ cut here ]------------
[  725.000185] WARNING: at net/sched/sch_generic.c:230 dev_watchdog+0xf5/0x186()
[  725.000226] Hardware name: GA-73PVM-S2H
[  725.000262] NETDEV WATCHDOG: eth1 (e100): transmit timed out
[  725.000299] Modules linked in: uio_sercos3 uio ipv6 sbp2 loop com20020_pci serio_raw com20020 e100 ohci1394 ohci_hcd amd74xx ehci_hcd arcnet parport_pc psmouse mii ieee1394 pcspkr usbcore ide_pci_generic parport evdev
[  725.000881] Pid: 5, comm: sirq-timer/0 Not tainted 2.6.29.5-rt22 #3
[  725.000919] Call Trace:
[  725.000957]  [<c012b571>] warn_slowpath+0x71/0xa8
[  725.000996]  [<c011d5fc>] ? pick_next_highest_task_rt+0xc6/0xd8
[  725.001039]  [<c011f3b1>] ? enqueue_task_rt+0x13a/0x232
[  725.001100]  [<c0348e00>] ? __read_trylock+0x3e/0x47
[  725.001139]  [<c0172136>] ? cpupri_set+0xdd/0xfb
[  725.001177]  [<c0162bed>] ? __rcu_read_unlock+0x69/0x78
[  725.001215]  [<c0348d5f>] ? __spin_unlock+0xf/0x23
[  725.001253]  [<c0174326>] ? perf_counter_task_sched_in+0x14e/0x15c
[  725.001293]  [<c021f8c2>] ? strlcpy+0x17/0x49
[  725.001331]  [<c02f398e>] dev_watchdog+0xf5/0x186
[  725.001369]  [<c0144fa1>] ? clocksource_watchdog+0x22f/0x23a
[  725.001408]  [<c0122d50>] ? __wake_up+0x28/0x32
[  725.001445]  [<c02f3899>] ? dev_watchdog+0x0/0x186
[  725.001484]  [<c013370c>] run_timer_softirq+0x19a/0x22a
[  725.001522]  [<c02f3899>] ? dev_watchdog+0x0/0x186
[  725.001560]  [<c012fb5a>] ksoftirqd+0x134/0x228
[  725.001597]  [<c012fa26>] ? ksoftirqd+0x0/0x228
[  725.001635]  [<c013c399>] kthread+0x3b/0x61
[  725.001672]  [<c013c35e>] ? kthread+0x0/0x61
[  725.001710]  [<c010350f>] kernel_thread_helper+0x7/0x10
[  725.001747] ---[ end trace 9b182b0252a7e099 ]---
[  725.014615] e100 0000:01:06.0: firmware: requesting e100/d101m_ucode.bin
[  725.029213] e100: eth1 NIC Link is Up 100 Mbps Full Duplex

What can I do to solve this issue?


Best regards, Hans-Peter
-- 
(°< Hans-Peter Bock, Dipl.-Ing., http://www.isw.uni-stuttgart.de/ >°)
(/) ISW - Universität Stuttgart, Seidenstraße 36, 70174 Stuttgart (\)

[-- Attachment #2: Type: application/pgp-signature, Size: 490 bytes --]

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: IRQ timeout
  2009-09-08 12:26 IRQ timeout Hans-Peter Bock
@ 2009-09-08 13:53 ` John Ogness
  2009-09-08 14:27   ` Hans-Peter Bock
  0 siblings, 1 reply; 6+ messages in thread
From: John Ogness @ 2009-09-08 13:53 UTC (permalink / raw)
  To: linux-rt-users; +Cc: Hans-Peter Bock

On 2009-09-08, Hans-Peter Bock <Hans-Peter.Bock@isw.uni-stuttgart.de> wrote:
> when I start my application using the uio_sercos3 driver, the network on my e100 stops working after a short time. Some miutes later I got this message in the console and my network started working again:
>
> [  725.000141] ------------[ cut here ]------------
> [  725.000185] WARNING: at net/sched/sch_generic.c:230 dev_watchdog+0xf5/0x186()
> [  725.000226] Hardware name: GA-73PVM-S2H
> [  725.000262] NETDEV WATCHDOG: eth1 (e100): transmit timed out
> [  725.000299] Modules linked in: uio_sercos3 uio ipv6 sbp2 loop com20020_pci serio_raw com20020 e100 ohci1394 ohci_hcd amd74xx ehci_hcd arcnet parport_pc psmouse mii ieee1394 pcspkr usbcore ide_pci_generic parport evdev
> [  725.000881] Pid: 5, comm: sirq-timer/0 Not tainted 2.6.29.5-rt22 #3
> [  725.000919] Call Trace:
> [  725.000957]  [<c012b571>] warn_slowpath+0x71/0xa8
> [  725.000996]  [<c011d5fc>] ? pick_next_highest_task_rt+0xc6/0xd8
> [  725.001039]  [<c011f3b1>] ? enqueue_task_rt+0x13a/0x232
> [  725.001100]  [<c0348e00>] ? __read_trylock+0x3e/0x47
> [  725.001139]  [<c0172136>] ? cpupri_set+0xdd/0xfb
> [  725.001177]  [<c0162bed>] ? __rcu_read_unlock+0x69/0x78
> [  725.001215]  [<c0348d5f>] ? __spin_unlock+0xf/0x23
> [  725.001253]  [<c0174326>] ? perf_counter_task_sched_in+0x14e/0x15c
> [  725.001293]  [<c021f8c2>] ? strlcpy+0x17/0x49
> [  725.001331]  [<c02f398e>] dev_watchdog+0xf5/0x186
> [  725.001369]  [<c0144fa1>] ? clocksource_watchdog+0x22f/0x23a
> [  725.001408]  [<c0122d50>] ? __wake_up+0x28/0x32
> [  725.001445]  [<c02f3899>] ? dev_watchdog+0x0/0x186
> [  725.001484]  [<c013370c>] run_timer_softirq+0x19a/0x22a
> [  725.001522]  [<c02f3899>] ? dev_watchdog+0x0/0x186
> [  725.001560]  [<c012fb5a>] ksoftirqd+0x134/0x228
> [  725.001597]  [<c012fa26>] ? ksoftirqd+0x0/0x228
> [  725.001635]  [<c013c399>] kthread+0x3b/0x61
> [  725.001672]  [<c013c35e>] ? kthread+0x0/0x61
> [  725.001710]  [<c010350f>] kernel_thread_helper+0x7/0x10
> [  725.001747] ---[ end trace 9b182b0252a7e099 ]---
> [  725.014615] e100 0000:01:06.0: firmware: requesting e100/d101m_ucode.bin
> [  725.029213] e100: eth1 NIC Link is Up 100 Mbps Full Duplex
>
> What can I do to solve this issue?

The following information would be helpful:

1. Is the uio_sercos3 driver sharing its interrupt?
   $ cat /proc/interrupts

2. What are the rt-priorities for your application (including the UIO
   thread) and for the network stack threads?
   $ ps -Alm

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

4. What is the system load while your application is running and when
   the network stops working?
   $ cat /proc/loadavg

5. Is your application doing anything particular with the network (such
   as tunneling Sercos data)?

John Ogness

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: IRQ timeout
  2009-09-08 13:53 ` John Ogness
@ 2009-09-08 14:27   ` Hans-Peter Bock
  2009-09-09  7:55     ` John Ogness
  0 siblings, 1 reply; 6+ messages in thread
From: Hans-Peter Bock @ 2009-09-08 14:27 UTC (permalink / raw)
  To: John Ogness; +Cc: linux-rt-users, Hans-Peter Bock

[-- Attachment #1: Type: text/plain, Size: 20589 bytes --]

Hello John,

> 1. Is the uio_sercos3 driver sharing its interrupt?
>    $ cat /proc/interrupts

no, it isn't:

           CPU0       CPU1       
 16:      26948          0   IO-APIC-fasteoi   Sercos_III_PCI
 17:        794          0   IO-APIC-fasteoi   eth1

But I am wondering, why CPU0 gets all the interrupts.


> 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
4 -     0     1     0  0   -   - -   525 -      ?        00:00:00 init
4 S     0     -     -  0  80   0 -     - poll_s -        00:00:00 -
5 -     0     2     0  0   -   - -     0 -      ?        00:00:00 kthreadd
5 S     0     -     -  0  75  -5 -     - kthrea -        00:00:00 -
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 -
1 -     0    15     2  0   -   - -     0 -      ?        00:00:00 desched/0
1 S     0     -     -  0  70 -10 -     - desche -        00:00:00 -
1 -     0    16     2  0   -   - -     0 -      ?        00:00:00 migration/1
1 S     0     -     -  0 -40   - -     - migrat -        00:00:00 -
1 -     0    17     2  0   -   - -     0 -      ?        00:00:00 posixcputmr/1
1 S     0     -     -  0 -40   - -     - posix_ -        00:00:00 -
5 -     0    18     2  0   -   - -     0 -      ?        00:00:00 sirq-high/1
5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
5 -     0    19     2  0   -   - -     0 -      ?        00:00:00 sirq-timer/1
5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
5 -     0    20     2  0   -   - -     0 -      ?        00:00:00 sirq-net-tx/1
5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
5 -     0    21     2  0   -   - -     0 -      ?        00:00:00 sirq-net-rx/1
5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
5 -     0    22     2  0   -   - -     0 -      ?        00:00:00 sirq-block/1
5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
5 -     0    23     2  0   -   - -     0 -      ?        00:00:00 sirq-tasklet/1
5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
5 -     0    24     2  0   -   - -     0 -      ?        00:00:00 sirq-sched/1
5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
5 -     0    25     2  0   -   - -     0 -      ?        00:00:00 sirq-hrtimer/1
5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
5 -     0    26     2  0   -   - -     0 -      ?        00:00:00 sirq-rcu/1
5 S     0     -     -  0  10   - -     - ksofti -        00:00:00 -
5 -     0    27     2  0   -   - -     0 -      ?        00:00:00 watchdog/1
5 S     0     -     -  0 -40   - -     - watchd -        00:00:00 -
1 -     0    28     2  0   -   - -     0 -      ?        00:00:00 desched/1
1 S     0     -     -  0  70 -10 -     - desche -        00:00:00 -
1 -     0    29     2  0   -   - -     0 -      ?        00:00:00 rcu_sched_grace
1 S     0     -     -  0  75  -5 -     - rcu_sc -        00:00:00 -
1 -     0    30     2  0   -   - -     0 -      ?        00:00:00 events/0
1 S     0     -     -  0  58   - -     - worker -        00:00:00 -
1 -     0    31     2  0   -   - -     0 -      ?        00:00:00 events/1
1 S     0     -     -  0  58   - -     - worker -        00:00:00 -
1 -     0    32     2  0   -   - -     0 -      ?        00:00:00 work_on_cpu/0
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0    33     2  0   -   - -     0 -      ?        00:00:00 work_on_cpu/1
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0    34     2  0   -   - -     0 -      ?        00:00:00 cpuset
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0    35     2  0   -   - -     0 -      ?        00:00:00 khelper
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0   119     2  0   -   - -     0 -      ?        00:00:00 kblockd/0
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0   120     2  0   -   - -     0 -      ?        00:00:00 kblockd/1
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0   122     2  0   -   - -     0 -      ?        00:00:00 kacpid
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0   123     2  0   -   - -     0 -      ?        00:00:00 kacpi_notify
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
7 -     0   124     2  0   -   - -     0 -      ?        00:00:00 IRQ-9
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
1 -     0   232     2  0   -   - -     0 -      ?        00:00:00 ata/0
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0   233     2  0   -   - -     0 -      ?        00:00:00 ata/1
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0   234     2  0   -   - -     0 -      ?        00:00:00 ata_aux
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0   236     2  0   -   - -     0 -      ?        00:00:00 kseriod
1 S     0     -     -  0  75  -5 -     - serio_ -        00:00:00 -
1 -     0   291     2  0   -   - -     0 -      ?        00:00:00 khungtaskd
1 S     0     -     -  0  80   0 -     - watchd -        00:00:00 -
1 -     0   292     2  0   -   - -     0 -      ?        00:00:00 pdflush
1 S     0     -     -  0  80   0 -     - pdflus -        00:00:00 -
1 -     0   293     2  0   -   - -     0 -      ?        00:00:00 pdflush
1 S     0     -     -  0  80   0 -     - pdflus -        00:00:00 -
1 -     0   294     2  0   -   - -     0 -      ?        00:00:00 kswapd0
1 S     0     -     -  0  75  -5 -     - kswapd -        00:00:00 -
1 -     0   295     2  0   -   - -     0 -      ?        00:00:00 aio/0
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0   296     2  0   -   - -     0 -      ?        00:00:00 aio/1
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
7 -     0   445     2  0   -   - -     0 -      ?        00:00:00 IRQ-27
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
1 -     0   446     2  0   -   - -     0 -      ?        00:00:00 scsi_eh_0
1 S     0     -     -  0  75  -5 -     - scsi_e -        00:00:00 -
1 -     0   448     2  0   -   - -     0 -      ?        00:00:00 scsi_eh_1
1 S     0     -     -  0  75  -5 -     - scsi_e -        00:00:00 -
1 -     0   450     2  0   -   - -     0 -      ?        00:00:00 scsi_eh_2
1 S     0     -     -  0  75  -5 -     - scsi_e -        00:00:00 -
1 -     0   452     2  0   -   - -     0 -      ?        00:00:00 scsi_eh_3
1 S     0     -     -  0  75  -5 -     - scsi_e -        00:00:00 -
7 -     0   477     2  0   -   - -     0 -      ?        00:00:00 IRQ-12
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
7 -     0   478     2  0   -   - -     0 -      ?        00:00:00 IRQ-1
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
7 -     0   485     2  0   -   - -     0 -      ?        00:00:00 IRQ-8
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
1 -     0   494     2  0   -   - -     0 -      ?        00:00:00 kjournald
1 S     0     -     -  0  75  -5 -     - kjourn -        00:00:00 -
5 -     0   593     1  0   -   - -   739 -      ?        00:00:00 udevd
5 S     0     -     -  0  76  -4 -     - poll_s -        00:00:00 -
1 -     0  1041     2  0   -   - -     0 -      ?        00:00:00 kpsmoused
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0  1045     2  0   -   - -     0 -      ?        00:00:00 khpsbpkt
1 S     0     -     -  0  75  -5 -     - hpsbpk -        00:00:00 -
1 -     0  1055     2  0   -   - -     0 -      ?        00:00:00 ksuspend_usbd
1 S     0     -     -  0  75  -5 -     - worker -        00:00:00 -
1 -     0  1057     2  0   -   - -     0 -      ?        00:00:00 khubd
1 S     0     -     -  0  75  -5 -     - hub_th -        00:00:00 -
7 -     0  1074     2  0   -   - -     0 -      ?        00:00:00 IRQ-7
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
7 -     0  1081     2  0   -   - -     0 -      ?        00:00:00 IRQ-22
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
7 -     0  1133     2  0   -   - -     0 -      ?        00:00:00 IRQ-18
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
1 -     0  1134     2  0   -   - -     0 -      ?        00:00:00 knodemgrd_0
1 S     0     -     -  0  75  -5 -     - nodemg -        00:00:00 -
7 -     0  1162     2  0   -   - -     0 -      ?        00:00:00 IRQ-14
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
7 -     0  1165     2  0   -   - -     0 -      ?        00:00:00 IRQ-21
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
7 -     0  1576     2  0   -   - -     0 -      ?        00:00:00 IRQ-17
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
1 -     0  1629     1  0   -   - -   454 -      ?        00:00:00 syslogd
1 S     0     -     -  0  80   0 -     - poll_s -        00:00:00 -
5 -     0  1638     1  0   -   - -   441 -      ?        00:00:00 klogd
5 S     0     -     -  0  80   0 -     - syslog -        00:00:00 -
1 -     0  1647     1  0   -   - -   441 -      ?        00:00:00 acpid
1 S     0     -     -  0  80   0 -     - poll_s -        00:00:00 -
5 -   105  1661     1  0   -   - -   655 -      ?        00:00:00 dbus-daemon
5 S   105     -     -  0  80   0 -     - poll_s -        00:00:00 -
5 -   106  1677     1  0   -   - -   721 -      ?        00:00:00 avahi-daemon
5 S   106     -     -  0  80   0 -     - poll_s -        00:00:00 -
1 -   106  1678  1677  0   -   - -   721 -      ?        00:00:00 avahi-daemon
1 S   106     -     -  0  80   0 -     - unix_s -        00:00:00 -
5 -     0  1702     1  0   -   - -  1354 -      ?        00:00:00 sshd
5 S     0     -     -  0  80   0 -     - poll_s -        00:00:00 -
1 -     0  1714     1  0   -   - -   722 -      ?        00:00:00 dirmngr
1 S     0     -     -  0  80   0 -     - poll_s -        00:00:00 -
5 -   100  1986     1  0   -   - -  1574 -      ?        00:00:00 exim4
5 S   100     -     -  0  80   0 -     - poll_s -        00:00:00 -
5 -     0  1998     1  0   -   - -   488 -      ?        00:00:00 inetd
5 S     0     -     -  0  80   0 -     - poll_s -        00:00:00 -
5 -   103  2015     1  0   -   - -  1069 -      ?        00:00:00 ntpd
5 S   103     -     -  0  80   0 -     - poll_s -        00:00:00 -
5 -   107  2027     1  0   -   - -  1431 -      ?        00:00:00 hald
5 S   107     -     -  0  80   0 -     - poll_s -        00:00:00 -
0 -     0  2028  2027  0   -   - -   831 -      ?        00:00:00 hald-runner
0 S     0     -     -  0  80   0 -     - poll_s -        00:00:00 -
0 -     0  2045  2028  0   -   - -   847 -      ?        00:00:00 hald-addon-inpu
0 S     0     -     -  0  80   0 -     - poll_s -        00:00:00 -
7 -     0  2048     2  0   -   - -     0 -      ?        00:00:00 IRQ-4
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
4 -   107  2055  2028  0   -   - -   568 -      ?        00:00:00 hald-addon-acpi
4 S   107     -     -  0  80   0 -     - unix_s -        00:00:00 -
0 -     0  2059  2028  0   -   - -   847 -      ?        00:00:00 hald-addon-stor
0 S     0     -     -  0  80   0 -     - poll_s -        00:00:00 -
1 -     1  2067     1  0   -   - -   512 -      ?        00:00:00 atd
1 S     1     -     -  0  80   0 -     - hrtime -        00:00:00 -
1 -     0  2087     1  0   -   - -   857 -      ?        00:00:00 cron
1 S     0     -     -  0  80   0 -     - hrtime -        00:00:00 -
4 -     0  2104     1  0   -   - -   657 -      tty1     00:00:00 login
4 S     0     -     -  0  80   0 -     - wait   -        00:00:00 -
4 -     0  2106     1  0   -   - -   657 -      tty2     00:00:00 login
4 S     0     -     -  0  80   0 -     - wait   -        00:00:00 -
0 -     0  2107     1  0   -   - -   441 -      tty3     00:00:00 getty
0 S     0     -     -  0  80   0 -     - n_tty_ -        00:00:00 -
0 -     0  2108     1  0   -   - -   441 -      tty4     00:00:00 getty
0 S     0     -     -  0  80   0 -     - n_tty_ -        00:00:00 -
0 -     0  2110     1  0   -   - -   441 -      tty5     00:00:00 getty
0 S     0     -     -  0  80   0 -     - n_tty_ -        00:00:00 -
0 -     0  2111     1  0   -   - -   441 -      tty6     00:00:00 getty
0 S     0     -     -  0  80   0 -     - n_tty_ -        00:00:00 -
4 -  1000  2149  2104  0   -   - -  1544 -      tty1     00:00:00 bash
4 S  1000     -     -  0  80   0 -     - wait   -        00:00:00 -
7 -     0  2196     2  0   -   - -     0 -      ?        00:00:00 IRQ-16
7 S     0     -     -  0   9   - -     - irqd   -        00:00:00 -
0 -  1000  2210  2149  0   -   - -  1026 -      tty1     00:00:00 screen
0 S  1000     -     -  0  80   0 -     - pause  -        00:00:00 -
1 -  1000  2211  2210  0   -   - -  1165 -      ?        00:00:00 screen
1 S  1000     -     -  0  80   0 -     - poll_s -        00:00:00 -
0 -  1000  2212  2211  0   -   - -  1514 -      pts/0    00:00:00 bash
0 S  1000     -     -  0  80   0 -     - wait   -        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 -
0 -  1000  2231  2211  0   -   - -  1514 -      pts/1    00:00:00 bash
0 S  1000     -     -  0  80   0 -     - wait   -        00:00:00 -
4 -     0  2251  2231  0   -   - - 17916 -      pts/1    00:00:00 v263_com
4 S     0     -     -  0  80   0 -     - hrtime -        00:00:00 -
0 -  1000  2252  2211  0   -   - -  1514 -      pts/2    00:00:00 bash
0 S  1000     -     -  0  80   0 -     - wait   -        00:00:00 -
4 -     0  2269  2252  0   -   - - 24749 -      pts/2    00:00:00 v263_sda
4 S     0     -     -  0  80   0 -     - hrtime -        00:00:00 -
0 -  1000  2270  2211  0   -   - -  1514 -      pts/3    00:00:00 bash
0 S  1000     -     -  0  80   0 -     - wait   -        00:00:00 -
4 -     0  2287  2270  0   -   - -  8518 -      pts/3    00:00:00 v263_init
4 S     0     -     -  0  80   0 -     - hrtime -        00:00:00 -
4 -  1000  2305  2106  0   -   - -  1513 -      tty2     00:00:00 bash
4 R  1000     -     -  0  80   0 -     - -      -        00:00:00 -
4 -     0  2340  1702  0   -   - -  2043 -      ?        00:00:00 sshd
4 S     0     -     -  0  80   0 -     - unix_s -        00:00:00 -
5 -  1000  2342  2340  0   -   - -  2081 -      ?        00:00:00 sshd
5 S  1000     -     -  0  80   0 -     - poll_s -        00:00:00 -
0 -  1000  2343  2342  0   -   - -  1514 -      pts/4    00:00:00 bash
0 S  1000     -     -  0  80   0 -     - n_tty_ -        00:00:00 -
0 -  1000  2368  2305  0   -   - -   872 -      tty2     00:00:00 ps
0 R  1000     -     -  0  80   0 -     - -      -        00:00:00 -


> 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       
  0:        125          0   IO-APIC-edge      timer
  1:        696          0   IO-APIC-edge      i8042
  4:          2          0   IO-APIC-edge    
  7:          1          0   IO-APIC-edge      parport0
  8:         45          0   IO-APIC-edge      rtc0
  9:          0          0   IO-APIC-fasteoi   acpi
 12:        105          0   IO-APIC-edge      i8042
 14:          0          0   IO-APIC-edge      ide0
 16:      26948          0   IO-APIC-fasteoi   Sercos_III_PCI
 17:        794          0   IO-APIC-fasteoi   eth1
 18:          3          0   IO-APIC-fasteoi   ohci1394
 21:          0          0   IO-APIC-fasteoi   ohci_hcd:usb2
 22:          0          0   IO-APIC-fasteoi   ehci_hcd:usb1
 27:       3698          0   PCI-MSI-edge      ahci
NMI:          0          0   Non-maskable interrupts
LOC:     129961      98461   Local timer interrupts
SPU:          0          0   Spurious interrupts
CNT:          0          0   Performance counter interrupts
RES:        169        515   Rescheduling interrupts
CAL:       1465        476   Function call interrupts
TLB:        174        258   TLB shootdowns
TRM:          0          0   Thermal event interrupts
ERR:          1
MIS:          0

           CPU0       CPU1       
  0:        125          0   IO-APIC-edge      timer
  1:        697          0   IO-APIC-edge      i8042
  4:          2          0   IO-APIC-edge    
  7:          1          0   IO-APIC-edge      parport0
  8:         45          0   IO-APIC-edge      rtc0
  9:          0          0   IO-APIC-fasteoi   acpi
 12:        105          0   IO-APIC-edge      i8042
 14:          0          0   IO-APIC-edge      ide0
 16:      27448          0   IO-APIC-fasteoi   Sercos_III_PCI
 17:        794          0   IO-APIC-fasteoi   eth1
 18:          3          0   IO-APIC-fasteoi   ohci1394
 21:          0          0   IO-APIC-fasteoi   ohci_hcd:usb2
 22:          0          0   IO-APIC-fasteoi   ehci_hcd:usb1
 27:       3712          0   PCI-MSI-edge      ahci
NMI:          0          0   Non-maskable interrupts
LOC:     130597      99473   Local timer interrupts
SPU:          0          0   Spurious interrupts
CNT:          0          0   Performance counter interrupts
RES:        171        516   Rescheduling interrupts
CAL:       1465        476   Function call interrupts
TLB:        174        259   TLB shootdowns
TRM:          0          0   Thermal event interrupts
ERR:          1
MIS:          0



> 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


> 5. Is your application doing anything particular with the network (such
>    as tunneling Sercos data)?

No. The only network data are some basic network services and ssh sessions.

If I plug out the network cable, and plug it in again, I get the previously posted error message and the network starts working again.


Best regards, Hans-Peter
-- 
(°< Hans-Peter Bock, Dipl.-Ing., http://www.isw.uni-stuttgart.de/ >°)
(/) ISW - Universität Stuttgart, Seidenstraße 36, 70174 Stuttgart (\)

[-- Attachment #2: Type: application/pgp-signature, Size: 490 bytes --]

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: IRQ timeout
  2009-09-08 14:27   ` Hans-Peter Bock
@ 2009-09-09  7:55     ` John Ogness
  2009-09-09 12:40       ` Hans-Peter Bock
  0 siblings, 1 reply; 6+ messages in thread
From: John Ogness @ 2009-09-09  7:55 UTC (permalink / raw)
  To: linux-rt-users; +Cc: Hans-Peter Bock

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

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: IRQ timeout
  2009-09-09  7:55     ` John Ogness
@ 2009-09-09 12:40       ` Hans-Peter Bock
  2009-09-09 12:48         ` Gregory Haskins
  0 siblings, 1 reply; 6+ messages in thread
From: Hans-Peter Bock @ 2009-09-09 12:40 UTC (permalink / raw)
  To: John Ogness; +Cc: linux-rt-users, Hans-Peter Bock

[-- Attachment #1: Type: text/plain, Size: 1150 bytes --]

Hello John,

how can I change the rt priority of a running process?


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

There is no timer, the geos thread sleeps on a conditional variable which is triggered by uio_sercos3 in the function UsrCb_t3().


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

The system actually is idle. The geos thread and the other CNC threads do not have much work to do since they were not completely ramped up.


Best regards, Hans-Peter
-- 
(°< Hans-Peter Bock, Dipl.-Ing., http://www.isw.uni-stuttgart.de/ >°)
(/) ISW - Universität Stuttgart, Seidenstraße 36, 70174 Stuttgart (\)

[-- Attachment #2: Type: application/pgp-signature, Size: 490 bytes --]

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: IRQ timeout
  2009-09-09 12:40       ` Hans-Peter Bock
@ 2009-09-09 12:48         ` Gregory Haskins
  0 siblings, 0 replies; 6+ messages in thread
From: Gregory Haskins @ 2009-09-09 12:48 UTC (permalink / raw)
  To: Hans-Peter Bock; +Cc: John Ogness, linux-rt-users

[-- Attachment #1: Type: text/plain, Size: 157 bytes --]

Hi Hans-Peter,

Hans-Peter Bock wrote:

> 
> how can I change the rt priority of a running process?
> 

"man chrt"

HTH

Kind Regards,
-Greg


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 267 bytes --]

^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2009-09-09 12:48 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2009-09-08 12:26 IRQ timeout Hans-Peter Bock
2009-09-08 13:53 ` John Ogness
2009-09-08 14:27   ` Hans-Peter Bock
2009-09-09  7:55     ` John Ogness
2009-09-09 12:40       ` Hans-Peter Bock
2009-09-09 12:48         ` Gregory Haskins

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox