LKML Archive on lore.kernel.org
help / color / mirror / Atom feed
* Spinlock debugging
@ 2006-09-11 15:32 Andrew Bird (Sphere Systems)
  2006-09-11 16:36 ` Alan Cox
  0 siblings, 1 reply; 8+ messages in thread
From: Andrew Bird (Sphere Systems) @ 2006-09-11 15:32 UTC (permalink / raw)
  To: linux-kernel

Hi all,
	this is my first post to the list, so please be kind. I am working on the 
nozomi (UMTS modem) driver, which is not in the main kernel.
I have a issue with the tty code. Currently the driver defines a 'put_char' 
tty function but it is empty, except for a debug message. Now I know that 
this means that the tty layer will use it to write single chars and so data 
will be lost. But if I comment out the line that tells the tty layer that 
it's implemented, I end up with a BUG - spinlock recursion. Can anybody tell 
me how to interpret the output?

Thanks and please CC as I'm not subscribed to the list

Andrew


[856] nozomi_read_config_table(): Initialization OK!
BUG: spinlock recursion on CPU#0, minicom/1918
 lock: dc4fade4, .magic: dead4ead, .owner: minicom/1918, .owner_cpu: 0
 [<c01bb897>] _raw_spin_lock+0x31/0x65
 [<c02c5fd6>] _spin_lock_irqsave+0x9/0xd
 [<e08b7de7>] ntty_write+0x35/0xf2 [nozomi]
 [<c0116672>] scheduler_tick+0x9d/0x2af
 [<c0106792>] timer_interrupt+0x73/0x7a
 [<c01fa505>] tty_default_put_char+0x15/0x18
 [<c01facfd>] opost+0x93/0x1ce
 [<c01fb96e>] n_tty_receive_buf+0x52b/0xb37
 [<c0103542>] common_interrupt+0x1a/0x20
 [<c011007b>] wakeup_code+0x7b/0xba
 [<c0119e01>] release_console_sem+0x74/0xa9
 [<c0119ce8>] vprintk+0x1d1/0x1f5
 [<c0106792>] timer_interrupt+0x73/0x7a
 [<c01ba361>] vsnprintf+0x45a/0x497
 [<c01fa14f>] flush_to_ldisc+0xd4/0xeb
 [<e08b67c3>] receive_data+0x1a6/0x1b6 [nozomi]
 [<c02c5fd6>] _spin_lock_irqsave+0x9/0xd
 [<c01204d3>] lock_timer_base+0x15/0x2f
 [<c02c5fd6>] _spin_lock_irqsave+0x9/0xd
 [<c01f64f0>] __add_entropy_words+0x58/0x167
 [<e08b6f92>] interrupt_handler+0x52c/0x723 [nozomi]
 [<c01addca>] __freed_request+0x1c/0x65
 [<c01ade30>] freed_request+0x1d/0x37
 [<c022d951>] __ide_end_request+0xb1/0xba
 [<c01ac11e>] elv_queue_empty+0x1b/0x21
 [<c022e922>] ide_do_request+0x89/0x2f8
 [<c022efa0>] ide_intr+0x10e/0x11a
 [<c02348ef>] ide_dma_intr+0x0/0x92
 [<c0133918>] handle_IRQ_event+0x21/0x4a
 [<c01339ba>] __do_IRQ+0x79/0xcb
 [<c010472a>] do_IRQ+0x5e/0x79
 =======================
 [<c0103542>] common_interrupt+0x1a/0x20
 [<c01f931a>] tty_open+0x276/0x2ac
 [<c0154f8c>] chrdev_open+0x111/0x127
 [<c0154e7b>] chrdev_open+0x0/0x127
 [<c014cc35>] __dentry_open+0xb6/0x185
 [<c014cdaa>] nameidata_to_filp+0x19/0x28
 [<c014cd2a>] filp_open+0x26/0x2c
 [<c014ceb0>] get_unused_fd+0xac/0xb4
 [<c014cf75>] do_sys_open+0x31/0x9c
 [<c0102b75>] syscall_call+0x7/0xb
BUG: spinlock lockup on CPU#0, minicom/1918, dc4fade4
 [<c01bb85d>] __spin_lock_debug+0x66/0x6f
 [<c01bb8bc>] _raw_spin_lock+0x56/0x65
 [<c02c5fd6>] _spin_lock_irqsave+0x9/0xd
 [<e08b7de7>] ntty_write+0x35/0xf2 [nozomi]
 [<c0116672>] scheduler_tick+0x9d/0x2af
 [<c0106792>] timer_interrupt+0x73/0x7a
 [<c01fa505>] tty_default_put_char+0x15/0x18
 [<c01facfd>] opost+0x93/0x1ce
 [<c01fb96e>] n_tty_receive_buf+0x52b/0xb37
 [<c0103542>] common_interrupt+0x1a/0x20
 [<c011007b>] wakeup_code+0x7b/0xba
 [<c0119e01>] release_console_sem+0x74/0xa9
 [<c0119ce8>] vprintk+0x1d1/0x1f5
 [<c0106792>] timer_interrupt+0x73/0x7a
 [<c01ba361>] vsnprintf+0x45a/0x497
 [<c01fa14f>] flush_to_ldisc+0xd4/0xeb
 [<e08b67c3>] receive_data+0x1a6/0x1b6 [nozomi]
 [<c02c5fd6>] _spin_lock_irqsave+0x9/0xd
 [<c01204d3>] lock_timer_base+0x15/0x2f
 [<c02c5fd6>] _spin_lock_irqsave+0x9/0xd
 [<c01f64f0>] __add_entropy_words+0x58/0x167
 [<e08b6f92>] interrupt_handler+0x52c/0x723 [nozomi]
 [<c01addca>] __freed_request+0x1c/0x65
 [<c01ade30>] freed_request+0x1d/0x37
 [<c022d951>] __ide_end_request+0xb1/0xba
 [<c01ac11e>] elv_queue_empty+0x1b/0x21
 [<c022e922>] ide_do_request+0x89/0x2f8
 [<c022efa0>] ide_intr+0x10e/0x11a
 [<c02348ef>] ide_dma_intr+0x0/0x92
 [<c0133918>] handle_IRQ_event+0x21/0x4a
 [<c01339ba>] __do_IRQ+0x79/0xcb
 [<c010472a>] do_IRQ+0x5e/0x79
 =======================
 [<c0103542>] common_interrupt+0x1a/0x20
 [<c01f931a>] tty_open+0x276/0x2ac
 [<c0154f8c>] chrdev_open+0x111/0x127
 [<c0154e7b>] chrdev_open+0x0/0x127
 [<c014cc35>] __dentry_open+0xb6/0x185
 [<c014cdaa>] nameidata_to_filp+0x19/0x28
 [<c014cd2a>] filp_open+0x26/0x2c
 [<c014ceb0>] get_unused_fd+0xac/0xb4
 [<c014cf75>] do_sys_open+0x31/0x9c
 [<c0102b75>] syscall_call+0x7/0xb

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

* Re: Spinlock debugging
  2006-09-11 15:32 Spinlock debugging Andrew Bird (Sphere Systems)
@ 2006-09-11 16:36 ` Alan Cox
  2006-09-11 16:38   ` Andrew Bird
  0 siblings, 1 reply; 8+ messages in thread
From: Alan Cox @ 2006-09-11 16:36 UTC (permalink / raw)
  To: Andrew Bird (Sphere Systems); +Cc: linux-kernel

Ar Llu, 2006-09-11 am 16:32 +0100, ysgrifennodd Andrew Bird (Sphere
Systems):
> will be lost. But if I comment out the line that tells the tty layer that 
> it's implemented, I end up with a BUG - spinlock recursion. Can anybody tell 
> me how to interpret the output?

Looks like your driver calls flush_to_ldisc with low latency set and
then can't handle the flush_to_ldisc causing n_tty to call back into the
write method for flow control.

Alan


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

* Re: Spinlock debugging
  2006-09-11 16:36 ` Alan Cox
@ 2006-09-11 16:38   ` Andrew Bird
  2006-09-11 17:24     ` Alan Cox
  0 siblings, 1 reply; 8+ messages in thread
From: Andrew Bird @ 2006-09-11 16:38 UTC (permalink / raw)
  To: Alan Cox; +Cc: linux-kernel

Alan
	Yes, I have low_latency set for kernels lower than 2.6.17. I'm currently 
testing using 2.6.15. When you mention 'write method for flow control' do you 
mean for software XON/XOFF etc?
	On a more generic note, is the spinlock debug output read as a stack and what 
do the '=======' line breaks signify, looping?

Thanks


Andrew

On Monday 11 September 2006 17:36, Alan Cox wrote:
> Ar Llu, 2006-09-11 am 16:32 +0100, ysgrifennodd Andrew Bird (Sphere
>
> Systems):
> > will be lost. But if I comment out the line that tells the tty layer that
> > it's implemented, I end up with a BUG - spinlock recursion. Can anybody
> > tell me how to interpret the output?
>
> Looks like your driver calls flush_to_ldisc with low latency set and
> then can't handle the flush_to_ldisc causing n_tty to call back into the
> write method for flow control.
>
> Alan

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

* Re: Spinlock debugging
  2006-09-11 16:38   ` Andrew Bird
@ 2006-09-11 17:24     ` Alan Cox
  2006-09-12  7:47       ` Andrew Bird
  0 siblings, 1 reply; 8+ messages in thread
From: Alan Cox @ 2006-09-11 17:24 UTC (permalink / raw)
  To: Andrew Bird; +Cc: linux-kernel

Ar Llu, 2006-09-11 am 17:38 +0100, ysgrifennodd Andrew Bird:
> Alan
> 	Yes, I have low_latency set for kernels lower than 2.6.17. I'm currently 
> testing using 2.6.15. When you mention 'write method for flow control' do you 
> mean for software XON/XOFF etc?

Yes

Basically in low_latency the following is valid


	driver receives bytes
		flush_to_ldisc
			ldisc calls driver write methods


That means if you have a shared lock for read/write you want to drop it
after you've bashed the hardware and before you flush_to_ldisc. Remember
the IRQ handler is not re-entrant so another IRQ of the same number
won't cause further I/O and out of order receives.

Alan


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

* Re: Spinlock debugging
  2006-09-11 17:24     ` Alan Cox
@ 2006-09-12  7:47       ` Andrew Bird
  2006-09-12 13:43         ` Alan Cox
  0 siblings, 1 reply; 8+ messages in thread
From: Andrew Bird @ 2006-09-12  7:47 UTC (permalink / raw)
  To: Alan Cox; +Cc: linux-kernel

Alan
	thanks that did the trick. 
One further question, on the later kernels 2.6.17+, I don't have low_latency 
set. Can I still guarantee that after calling tty_flip_buffer_push() I have 
made space in the tty for my buffer? For example, is this legal? 

// in interrupt handler

   if(tty_buffer_request_room(tty, size) < size) {

      spin_unlock(&dc->lock);
      spin_unlock(&port->lock);

      tty_flip_buffer_push(tty);

      spin_lock(&port->lock);
      spin_lock(&dc->lock);

  }
  tty_insert_flip_string(tty, buf, size);
   
Thanks


Andrew

On Monday 11 September 2006 18:24, Alan Cox wrote:
> Ar Llu, 2006-09-11 am 17:38 +0100, ysgrifennodd Andrew Bird:
> > Alan
> > 	Yes, I have low_latency set for kernels lower than 2.6.17. I'm currently
> > testing using 2.6.15. When you mention 'write method for flow control' do
> > you mean for software XON/XOFF etc?
>
> Yes
>
> Basically in low_latency the following is valid
>
>
> 	driver receives bytes
> 		flush_to_ldisc
> 			ldisc calls driver write methods
>
>
> That means if you have a shared lock for read/write you want to drop it
> after you've bashed the hardware and before you flush_to_ldisc. Remember
> the IRQ handler is not re-entrant so another IRQ of the same number
> won't cause further I/O and out of order receives.
>
> Alan

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

* Re: Spinlock debugging
  2006-09-12 13:43         ` Alan Cox
@ 2006-09-12 13:31           ` Sergei Organov
  2006-09-12 14:04             ` Alan Cox
  0 siblings, 1 reply; 8+ messages in thread
From: Sergei Organov @ 2006-09-12 13:31 UTC (permalink / raw)
  To: Alan Cox; +Cc: Andrew Bird, linux-kernel

Alan Cox <alan@lxorguk.ukuu.org.uk> writes:
[...]
> So all you need in your IRQ handler is
>
> 	if (tty_insert_flip_string(tty, buf, size))
> 		tty_flip_buffer_push(tty);

What is the purpose of the "if" in the above code?  is push with no data
in the buffer dangerous? Or is it just optimization of
almost-never-taken path? ;)

-- Sergei.

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

* Re: Spinlock debugging
  2006-09-12  7:47       ` Andrew Bird
@ 2006-09-12 13:43         ` Alan Cox
  2006-09-12 13:31           ` Sergei Organov
  0 siblings, 1 reply; 8+ messages in thread
From: Alan Cox @ 2006-09-12 13:43 UTC (permalink / raw)
  To: Andrew Bird; +Cc: linux-kernel

Ar Maw, 2006-09-12 am 08:47 +0100, ysgrifennodd Andrew Bird:
> Alan
> 	thanks that did the trick. 
> One further question, on the later kernels 2.6.17+, I don't have low_latency 
> set. Can I still guarantee that after calling tty_flip_buffer_push() I have 
> made space in the tty for my buffer? For example, is this legal? 

It makes no guarantee in any kernel.

In the new tty case however tty_buffer_request_room() will only fail if
you have 64K queued or the box is completely out of atomic memory and
also doing stuff like dropping network packets and console keystrokes.

So all you need in your IRQ handler is

	if (tty_insert_flip_string(tty, buf, size))
		tty_flip_buffer_push(tty);

the rest will occur automatically. Hinting with tty_buffer_request_room
may improve performance for some workloads (notably virtualized uarts)
or when using DMA but otherwise the above should be fine.

Most existing drivers were a straight conversion so at the moment try
too hard.



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

* Re: Spinlock debugging
  2006-09-12 13:31           ` Sergei Organov
@ 2006-09-12 14:04             ` Alan Cox
  0 siblings, 0 replies; 8+ messages in thread
From: Alan Cox @ 2006-09-12 14:04 UTC (permalink / raw)
  To: Sergei Organov; +Cc: Andrew Bird, linux-kernel

Ar Maw, 2006-09-12 am 17:31 +0400, ysgrifennodd Sergei Organov:
> Alan Cox <alan@lxorguk.ukuu.org.uk> writes:
> [...]
> > So all you need in your IRQ handler is
> >
> > 	if (tty_insert_flip_string(tty, buf, size))
> > 		tty_flip_buffer_push(tty);
> 
> What is the purpose of the "if" in the above code?  is push with no data
> in the buffer dangerous? Or is it just optimization of
> almost-never-taken path? ;)

Sorry..replied to sender only

It's an optimisation and you are right it may well not even be worth
doing


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

end of thread, other threads:[~2006-09-12 13:41 UTC | newest]

Thread overview: 8+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2006-09-11 15:32 Spinlock debugging Andrew Bird (Sphere Systems)
2006-09-11 16:36 ` Alan Cox
2006-09-11 16:38   ` Andrew Bird
2006-09-11 17:24     ` Alan Cox
2006-09-12  7:47       ` Andrew Bird
2006-09-12 13:43         ` Alan Cox
2006-09-12 13:31           ` Sergei Organov
2006-09-12 14:04             ` Alan Cox

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).