irq 4: nobody cared and I/O errors on serial ports.

Hello,

It seems that the kernel has some problems/races in opening/closing of serial ports. Simple C program below just opens/closes a port in a loop:

#include <stdio.h>
#include <unistd.h>
#include <errno.h>
#include <fcntl.h>

int main()
{

  while(1) {
    int fd = open("/dev/ttyS0", O_RDONLY | O_NOCTTY);
    if(fd < 0)
      fprintf(stderr, "%s\n", strerror(errno));
    else
      close(fd);

}
}

I've noticed 2 problems running this program. I run 2.6.19.1 smp kernel (I've also tested Debian 2.6.18.3 kernel, and it has the same issues) on hyper-threaded Pentium 4 CPU.

1. When I run the program, I begin to get "irq 4: nobody cared" in dmesg even though the port is not connected (idle). Please find relevant part of dmesg below.

2. When two copies of this program are run simultaneously, each of copies start to randomly fail to open the port with errno=5 (Input/output error).

Note that I've tested this both with standard PC port ttyS0 and with serial ports of MOXA multi-port serial board (ttyM*), and [mis]behavior is the same. Also note that opening /dev/null instead of serial port doesn't have any problems.

Here are relevant parts from dmesg when open/close ttyS0:

irq 4: nobody cared (try booting with the "irqpoll" option)

 [<c0144ef2>] __report_bad_irq+0x36/0x7d
 [<c01450f4>] note_interrupt+0x1bb/0x1f7
 [<c0144665>] handle_IRQ_event+0x1a/0x3f
 [<c01458fd>] handle_edge_irq+0xde/0x109
 [<c010537d>] do_IRQ+0x7d/0xa4
 [<c01036ee>] common_interrupt+0x1a/0x20
 [<c01036ee>] common_interrupt+0x1a/0x20
 [<c021b63e>] serial_out+0x73/0x77
 [<c021cbb1>] serial8250_shutdown+0x71/0x148
 [<c0219c57>] uart_shutdown+0x83/0xad
 [<c021b16b>] uart_close+0x113/0x1a9
 [<c0209bf9>] tty_fasync+0x3a/0xaa
 [<c0209e48>] release_dev+0x1df/0x61e
 [<c016286d>] chrdev_open+0x12d/0x141
 [<c0162740>] chrdev_open+0x0/0x141
 [<c015ed34>] nameidata_to_filp+0x24/0x33
 [<c015ed75>] do_filp_open+0x32/0x39
 [<c01c1fa4>] __next_cpu+0x12/0x21
 [<c02964a3>] __sched_text_start+0x5a3/0x90a
 [<c020a296>] tty_release+0xf/0x18
 [<c0160f29>] __fput+0x96/0x16a
 [<c015ea56>] filp_close+0x52/0x59
 [<c015fa2b>] sys_close+0x65/0x99
 [<c0102cfd>] sysenter_past_esp+0x56/0x79
 =======================

handlers:
[<c021d9d4>] (serial8250_interrupt+0x0/0xdc) Disabling IRQ #4
irq 4: nobody cared (try booting with the "irqpoll" option)

 [<c0144ef2>] __report_bad_irq+0x36/0x7d
 [<c01450f4>] note_interrupt+0x1bb/0x1f7
 [<c0144665>] handle_IRQ_event+0x1a/0x3f
 [<c01458fd>] handle_edge_irq+0xde/0x109
 [<c010537d>] do_IRQ+0x7d/0xa4
 [<c01036ee>] common_interrupt+0x1a/0x20
 [<c0101235>] mwait_idle_with_hints+0x3b/0x3f
 [<c0101245>] mwait_idle+0xc/0x1b
 [<c0101c7f>] cpu_idle+0x9f/0xb9
 [<c0333753>] start_kernel+0x39f/0x3a7
 [<c03331ae>] unknown_bootoption+0x0/0x206
 =======================
handlers:
Disabling IRQ #4
irq 4: nobody cared (try booting with the "irqpoll" option)
 [<c0144ef2>] __report_bad_irq+0x36/0x7d
 [<c01450f4>] note_interrupt+0x1bb/0x1f7
 [<c0144665>] handle_IRQ_event+0x1a/0x3f
 [<c01458fd>] handle_edge_irq+0xde/0x109
 [<c010537d>] do_IRQ+0x7d/0xa4
 [<c01036ee>] common_interrupt+0x1a/0x20
 [<c0101235>] mwait_idle_with_hints+0x3b/0x3f
 [<c0101245>] mwait_idle+0xc/0x1b
 [<c0101c7f>] cpu_idle+0x9f/0xb9
 [<c0333753>] start_kernel+0x39f/0x3a7
 [<c03331ae>] unknown_bootoption+0x0/0x206
 =======================
handlers:
Disabling IRQ #4
irq 4: nobody cared (try booting with the "irqpoll" option)
 [<c0144ef2>] __report_bad_irq+0x36/0x7d
 [<c01450f4>] note_interrupt+0x1bb/0x1f7
 [<c0144665>] handle_IRQ_event+0x1a/0x3f
 [<c01458fd>] handle_edge_irq+0xde/0x109
 [<c010537d>] do_IRQ+0x7d/0xa4
 [<c01036ee>] common_interrupt+0x1a/0x20
 [<c01036ee>] common_interrupt+0x1a/0x20
 [<c021b63e>] serial_out+0x73/0x77
 [<c021cbcb>] serial8250_shutdown+0x8b/0x148
 [<c0219c57>] uart_shutdown+0x83/0xad
 [<c021b16b>] uart_close+0x113/0x1a9
 [<c0209bf9>] tty_fasync+0x3a/0xaa
 [<c0209e48>] release_dev+0x1df/0x61e
 [<c016286d>] chrdev_open+0x12d/0x141
 [<c0162740>] chrdev_open+0x0/0x141
 [<c015ed34>] nameidata_to_filp+0x24/0x33
 [<c015ed75>] do_filp_open+0x32/0x39
 [<c01c1fa4>] __next_cpu+0x12/0x21
 [<c02964a3>] __sched_text_start+0x5a3/0x90a
 [<c020a296>] tty_release+0xf/0x18
 [<c0160f29>] __fput+0x96/0x16a
 [<c015ea56>] filp_close+0x52/0x59
 [<c015fa2b>] sys_close+0x65/0x99
 [<c0102cfd>] sysenter_past_esp+0x56/0x79
 =======================

handlers:
[<c021d9d4>] (serial8250_interrupt+0x0/0xdc) Disabling IRQ #4
irq 4: nobody cared (try booting with the "irqpoll" option)

 [<c0144ef2>] __report_bad_irq+0x36/0x7d
 [<c01450f4>] note_interrupt+0x1bb/0x1f7
 [<c0144665>] handle_IRQ_event+0x1a/0x3f
 [<c01458fd>] handle_edge_irq+0xde/0x109
 [<c010537d>] do_IRQ+0x7d/0xa4
 [<c01036ee>] common_interrupt+0x1a/0x20
 [<c0101235>] mwait_idle_with_hints+0x3b/0x3f
 [<c0101245>] mwait_idle+0xc/0x1b
 [<c0101c7f>] cpu_idle+0x9f/0xb9
 [<c0333753>] start_kernel+0x39f/0x3a7
 [<c03331ae>] unknown_bootoption+0x0/0x206
 =======================

handlers:
Disabling IRQ #4

Sergei Organov.

Also happens on 2.6.18.5 on AMD AXP2000 (UP, CONFIG_SMP=y), standard x86 pc serial port
serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A 00:09: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A

Running said program repeatedly produces one stack trace every 4 seconds (CONFIG_HZ=100). Maybe knowing this interval helps finding the problem.

[ 9545.167750] Disabling IRQ #4
[ 9549.599704] Disabling IRQ #4
[ 9554.034803] Disabling IRQ #4
[ 9558.455093] Disabling IRQ #4
[ 9562.876508] Disabling IRQ #4

	-`J'