Hi all,
I have upgraded one of my automated test setups from 2.6.27 to 2.6.29. I
now have issues with using a Moxa multiport serial device, where I had
none before :-)
> MOXA Smartio/Industio family driver version 2.0.4
> mxser 0000:03:02.0: found MOXA C168H/PCI series board (BusNo=3,
DevNo=2)
> mxser 0000:03:02.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
> mxser: max. baud rate = 921600 bps
When I cat /dev/setup3 (which is a symlink to /dev/ttyMI3), which is
connected to a device that outputs data (tried it with one @ 115200bps
and one @ 9600bps), I get the following kernel trace:
------------[ cut here ]------------
WARNING: at kernel/mutex.c:135 __mutex_lock_slowpath+0x50/0x211()
Hardware name: OptiPlex 755
Modules linked in: i915 drm i2c_algo_bit ipv6 8021q dummy fuse arc4 ecb
snd_hda_codec_analog snd_hda_intel snd_hda_codec rtl8187 mac80211 usbhid
i2c_i801 snd_pcm serio_raw eeprom_93cx6 iTCO_wdt i2c_core
iTCO_vendor_support cfg80211 snd_timer snd snd_page_alloc rtc_cmos
rtc_core intel_agp agpgart mxser ppdev thermal uhci_hcd sg rtc_lib
parport_pc processor parport button thermal_sys dcdbas
Pid: 0, comm: swapper Not tainted 2.6.29-autodistro-r4 #1
Call Trace:
[<c0127479>] warn_slowpath+0x74/0x8a
[<c016bb1a>] ? get_page_from_freelist+0xc1/0x3c6
[<c04e0093>] ? usb_hcd_submit_urb+0x88d/0x95b
[<c05d2d41>] ? _spin_lock+0x8/0xb
[<c0187063>] ? cache_alloc_refill+0x19f/0x499
[<c05d1b63>] __mutex_lock_slowpath+0x50/0x211
[<c05d1d36>] mutex_lock+0x12/0x15
[<c026d677>] echo_set_canon_col+0x14/0x37
[<c026e478>] n_tty_receive_buf+0x2f3/0xe0c
[<c05d2d41>] ? _spin_lock+0x8/0xb
[<c0187063>] ? cache_alloc_refill+0x19f/0x499
[<c05d2e5e>] ? _spin_lock_irqsave+0x28/0x2f
[<c012f01d>] ? lock_timer_base+0x1f/0x3e
[<c0118b2d>] ? default_spin_lock_flags+0x8/0xb
[<c0118b2d>] ? default_spin_lock_flags+0x8/0xb
[<c02710ed>] flush_to_ldisc+0xe9/0x159
[<c027119e>] tty_flip_buffer_push+0x41/0x51
[<f842e5f5>] mxser_receive_chars+0x237/0x246 [mxser]
[<f842fac5>] mxser_interrupt+0x18e/0x228 [mxser]
[<c015ac54>] handle_IRQ_event+0x2a/0x5a
[<c015c11a>] handle_fasteoi_irq+0x7b/0xb4
[<c015c09f>] ? handle_fasteoi_irq+0x0/0xb4
<IRQ> [<c0103527>] ? common_interrupt+0x27/0x2c
[<c0108131>] ? mwait_idle+0x4c/0x5b
[<c0101a5b>] ? cpu_idle+0x59/0x6d
[<c05ce807>] ? start_secondary+0x19f/0x1a4
---[ end trace 433a17e91cdf059a ]---
After I break the cat, subsequent cat's result in:
cat /dev/setup3
cat: /dev/setup3: Input/output error
I'm not a kernel expert, so if you have any pointers or ways to provide
more information, don't hesitate to ask.
Regards,
Christophe L.
On Thu, 2009-04-02 at 18:26 +0200, Christophe Lermytte wrote:
> Hi all,
>
> I have upgraded one of my automated test setups from 2.6.27 to 2.6.29. I
> now have issues with using a Moxa multiport serial device, where I had
> none before :-)
>
> > MOXA Smartio/Industio family driver version 2.0.4
> > mxser 0000:03:02.0: found MOXA C168H/PCI series board (BusNo=3,
> DevNo=2)
> > mxser 0000:03:02.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18
> > mxser: max. baud rate = 921600 bps
>
> When I cat /dev/setup3 (which is a symlink to /dev/ttyMI3), which is
> connected to a device that outputs data (tried it with one @ 115200bps
> and one @ 9600bps), I get the following kernel trace:
>
> ------------[ cut here ]------------
> WARNING: at kernel/mutex.c:135 __mutex_lock_slowpath+0x50/0x211()
> Hardware name: OptiPlex 755
> Modules linked in: i915 drm i2c_algo_bit ipv6 8021q dummy fuse arc4 ecb
> snd_hda_codec_analog snd_hda_intel snd_hda_codec rtl8187 mac80211 usbhid
> i2c_i801 snd_pcm serio_raw eeprom_93cx6 iTCO_wdt i2c_core
> iTCO_vendor_support cfg80211 snd_timer snd snd_page_alloc rtc_cmos
> rtc_core intel_agp agpgart mxser ppdev thermal uhci_hcd sg rtc_lib
> parport_pc processor parport button thermal_sys dcdbas
> Pid: 0, comm: swapper Not tainted 2.6.29-autodistro-r4 #1
> Call Trace:
> [<c0127479>] warn_slowpath+0x74/0x8a
> [<c016bb1a>] ? get_page_from_freelist+0xc1/0x3c6
> [<c04e0093>] ? usb_hcd_submit_urb+0x88d/0x95b
> [<c05d2d41>] ? _spin_lock+0x8/0xb
> [<c0187063>] ? cache_alloc_refill+0x19f/0x499
> [<c05d1b63>] __mutex_lock_slowpath+0x50/0x211
> [<c05d1d36>] mutex_lock+0x12/0x15
> [<c026d677>] echo_set_canon_col+0x14/0x37
> [<c026e478>] n_tty_receive_buf+0x2f3/0xe0c
> [<c05d2d41>] ? _spin_lock+0x8/0xb
> [<c0187063>] ? cache_alloc_refill+0x19f/0x499
> [<c05d2e5e>] ? _spin_lock_irqsave+0x28/0x2f
> [<c012f01d>] ? lock_timer_base+0x1f/0x3e
> [<c0118b2d>] ? default_spin_lock_flags+0x8/0xb
> [<c0118b2d>] ? default_spin_lock_flags+0x8/0xb
> [<c02710ed>] flush_to_ldisc+0xe9/0x159
> [<c027119e>] tty_flip_buffer_push+0x41/0x51
> [<f842e5f5>] mxser_receive_chars+0x237/0x246 [mxser]
> [<f842fac5>] mxser_interrupt+0x18e/0x228 [mxser]
> [<c015ac54>] handle_IRQ_event+0x2a/0x5a
> [<c015c11a>] handle_fasteoi_irq+0x7b/0xb4
> [<c015c09f>] ? handle_fasteoi_irq+0x0/0xb4
> <IRQ> [<c0103527>] ? common_interrupt+0x27/0x2c
> [<c0108131>] ? mwait_idle+0x4c/0x5b
> [<c0101a5b>] ? cpu_idle+0x59/0x6d
> [<c05ce807>] ? start_secondary+0x19f/0x1a4
> ---[ end trace 433a17e91cdf059a ]---
It appears to want to lock a mutex in interrupt context, something
that's a definite no-no.
CCed the folks who might know a thing or two about the driver.
> It appears to want to lock a mutex in interrupt context, something
> that's a definite no-no.
>
> CCed the folks who might know a thing or two about the driver.
Moxa is not a USB driver so the USB trace at the end makes no sense at
all.
Alan
On 04/02/2009 08:44 PM, Alan Cox wrote:
>> It appears to want to lock a mutex in interrupt context, something
>> that's a definite no-no.
>>
>> CCed the folks who might know a thing or two about the driver.
>
> Moxa is not a USB driver so the USB trace at the end makes no sense at
> all.
Yes, unreliable stack entries, but echo_set_canon_col is called from irq
context and locks mutex.
> > It appears to want to lock a mutex in interrupt context, something
> > that's a definite no-no.
> >
> > CCed the folks who might know a thing or two about the driver.
> Moxa is not a USB driver so the USB trace at the end makes no sense at
> all.
Well, it's not that I faked the traces ;-)
During the first cat, I can see the data transmitted by the device, so I guess the kernel warning is not really blocking for me at this point.
What is blocking, is the fact that I can only do it once, before I get the input/output error. I found a post about this ( http://lkml.org/lkml/2009/3/24/269 ) and the patch seems to have made it into 2.6.29. Still having a similar issue though...
Regards,
Christophe L.
On Thu, 02 Apr 2009 22:23:57 +0200
Jiri Slaby <[email protected]> wrote:
> On 04/02/2009 08:44 PM, Alan Cox wrote:
> >> It appears to want to lock a mutex in interrupt context, something
> >> that's a definite no-no.
> >>
> >> CCed the folks who might know a thing or two about the driver.
> >
> > Moxa is not a USB driver so the USB trace at the end makes no sense at
> > all.
>
> Yes, unreliable stack entries, but echo_set_canon_col is called from irq
> context and locks mutex.
Which means that either the driver is calling the ldisc receive handlers
from an IRQ directly (not allowed) or calling the tty_flip_buffer_push
paths and set tty->low_latency
2.6.29 is the first kernel that catches this bug with warnings.
On Thu, Apr 02, 2009 at 11:55:08PM +0100, Alan Cox wrote:
> On Thu, 02 Apr 2009 22:23:57 +0200
> Jiri Slaby <[email protected]> wrote:
>
> > On 04/02/2009 08:44 PM, Alan Cox wrote:
> > >> It appears to want to lock a mutex in interrupt context, something
> > >> that's a definite no-no.
> > >>
> > >> CCed the folks who might know a thing or two about the driver.
> > >
> > > Moxa is not a USB driver so the USB trace at the end makes no sense at
> > > all.
> >
> > Yes, unreliable stack entries, but echo_set_canon_col is called from irq
> > context and locks mutex.
>
> Which means that either the driver is calling the ldisc receive handlers
> from an IRQ directly (not allowed) or calling the tty_flip_buffer_push
> paths and set tty->low_latency
>
> 2.6.29 is the first kernel that catches this bug with warnings.
It sets tty->low_latency = 1 on ->open(), unconditionally, and does
tty_flip_buffer_push() from the interrupt handler.
Both things seem to have been there for a very long time (git-blame
says longer than git).
On 04/03/2009 02:33 AM, Johannes Weiner wrote:
> On Thu, Apr 02, 2009 at 11:55:08PM +0100, Alan Cox wrote:
>> On Thu, 02 Apr 2009 22:23:57 +0200
>> Jiri Slaby <[email protected]> wrote:
>>
>>> On 04/02/2009 08:44 PM, Alan Cox wrote:
>>>>> It appears to want to lock a mutex in interrupt context, something
>>>>> that's a definite no-no.
>>>>>
>>>>> CCed the folks who might know a thing or two about the driver.
>>>> Moxa is not a USB driver so the USB trace at the end makes no sense at
>>>> all.
>>> Yes, unreliable stack entries, but echo_set_canon_col is called from irq
>>> context and locks mutex.
>> Which means that either the driver is calling the ldisc receive handlers
>> from an IRQ directly (not allowed) or calling the tty_flip_buffer_push
>> paths and set tty->low_latency
>>
>> 2.6.29 is the first kernel that catches this bug with warnings.
>
> It sets tty->low_latency = 1 on ->open(), unconditionally, and does
> tty_flip_buffer_push() from the interrupt handler.
>
> Both things seem to have been there for a very long time (git-blame
> says longer than git).
I have no idea why it was added in fact and so whether it is sufficient
and correct just to remove the tty->low_latency setting hence I can't
fix it on my own.
It was added when Alan merged moxa's updated driver in (from
full-linux-history git):
commit c8caa4c1a9cda2fa01fa89c29020e31f5a923e0b
Author: Alan Cox <[email protected]>
Date: Wed Dec 22 01:14:43 2004 -0800
[PATCH] Bring Moxa serial back into being
Moxa have released several driver updates now including support up to
2.6.8 but don't themselves feel its worth the effort of doing a cleaned
up merge for the base kernel. So I pulled their latest driver release
(1.8) and removed all the macro gunge that makes it build on
2.2.0->2.6.8. I then fixed it to run on 2.6.9/10 and fixed a bug in the
break handling.
It still doesn't do PCI hotplug but I don't have any PCI moxa cards to
really tackle that particular case.
I've also merged Adriank Bunk's two 'could be static' changes into this
diff set.