[RFC v2]: Issues implementing clock handling mechanism within UART driver

[RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj.R]

To handle uart clocks within uart driver we need the *semantics of clock enable
API should not internally trigger any UART PORT operation* even before
completing clock_enable.

Ex: while configuring baud rate we may use runtime api's to enable uart port.
get_sync -> printk -> call console uart to print

For example, say we are calling Uart_configure baud to configure the baud-rate.
Even before this operation completes, if there is print, we may switch to uart
write operation which is undesirable.

This occurs due to any printks called from omap_device ()/omap_hwmod ()/clk layers
which come in the flow from pm_runtime_get_sync/ pm_runtime_put_autosuspend API's.

	1. pm_runtime_get _sync -> printk -> console_write -> pm_runtime_get_sync
	2. pm_runtime_ put_autosuspend -> rpm_suspend -> pm_generic suspend ->
	   omap_device_disable -> debug prints -> console_write -> pm_runtime_get_sync

This leads to a deadlock caused by contention of the power_lock from
the same runtime API context.

Work-around explored:
--------------------
Use console lock aggressively around each get_sync/put_sync.

	Uart_configure baud {
		1. Console_lock
		2. pm_runtime_get_sync
		3. Console_unlock (and send the prints accumulated in the
		   log buffer to the console) which leads to a console_write .
		4. This console_write in turn leads to a console_lock+pm_runtime_get_sync
		5. Also  Console_unlock is undesirable here since it jumps to
		   console write even before baud config was complete.
	}

Locking the console around a pm_runtime_get_sync()will make sure that all prints
are sent to the log-buffer until the console in unlocked, thereby getting rid of
recursively jumping from one port op to another even before current port
operation is complete.

However, this leads to:
	1. Cant bind put_autosuspend with console lock as they get scheduled later
	   put -> print -> console_write -> get_sync (one runtime API context we
	   may enter another runtime API power lock contention)
	2. Using console_lock wrapper everywhere in driver to suppress prints
	   from get_sync is too aggressive in nature.
	3. During Boot-up, console_lock is not available until uart driver
	   completes its registration with kernel console_driver.

Observing the semantics of console_lock/unlock, it seems undesirable to be used
within uart driver. But can rather be used form global stand point to suppress
uart prints.

Example:
1. While system wide suspending
2. In cpu idle path., etc.

Proposal:
--------
	1. For the UART, follow the current approach of locking the console in
	   Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
	   That is, continue using the prepare/resume Idle calls in idle path.
	2. Other Approach would be adding conditions to debug prints from
	   omap_device/ omap_hwmod/clock_framework avoid calling these debug
	   prints for uart.
	   Or Even a debug macro that would not debug prints if the context is
	   from uart.

Any further approaches are welcome.

Have captured little more details compared to v1 posted erlier:
http://www.mail-archive.com/linux-omap@vger.kernel.org/msg52707.html

-- 
1.7.4.1

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

[-- Attachment #1.1: Type: text/plain, Size: 1159 bytes --]

Hi,

On Thu, Jul 28, 2011 at 02:59:55PM +0530, Govindraj.R wrote:
> Proposal:
> --------
> 	1. For the UART, follow the current approach of locking the console in
> 	   Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
> 	   That is, continue using the prepare/resume Idle calls in idle path.

I believe you should be using ->prepare() to prevent that any other
work on UART won't trigger a console_write() right now. Maybe only
queueing the work for after ->complete() or, maybe, just ignoring the
work and loosing some prints, dunno.

> 	2. Other Approach would be adding conditions to debug prints from
> 	   omap_device/ omap_hwmod/clock_framework avoid calling these debug
> 	   prints for uart.
> 	   Or Even a debug macro that would not debug prints if the context is
> 	   from uart.

yeah, that might work but then again, if we were using 8250.c, would we
have this limitation ??

I think that, maybe, your best call would be to capture console_write()
calls into an internal temporary buffer on ->prepare() and flush it once
->complete() is called ?

BTW, where are the patches ? :-)

-- 
balbi

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

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

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

Hi,

On Thu, Jul 28, 2011 at 02:59:55PM +0530, Govindraj.R wrote:
> Proposal:
> --------
> 	1. For the UART, follow the current approach of locking the console in
> 	   Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
> 	   That is, continue using the prepare/resume Idle calls in idle path.

I believe you should be using ->prepare() to prevent that any other
work on UART won't trigger a console_write() right now. Maybe only
queueing the work for after ->complete() or, maybe, just ignoring the
work and loosing some prints, dunno.

> 	2. Other Approach would be adding conditions to debug prints from
> 	   omap_device/ omap_hwmod/clock_framework avoid calling these debug
> 	   prints for uart.
> 	   Or Even a debug macro that would not debug prints if the context is
> 	   from uart.

yeah, that might work but then again, if we were using 8250.c, would we
have this limitation ??

I think that, maybe, your best call would be to capture console_write()
calls into an internal temporary buffer on ->prepare() and flush it once
->complete() is called ?

BTW, where are the patches ? :-)

-- 
balbi

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

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Fri, Jul 29, 2011 at 3:25 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>

Thanks for replying.

> On Thu, Jul 28, 2011 at 02:59:55PM +0530, Govindraj.R wrote:
>> Proposal:
>> --------
>>       1. For the UART, follow the current approach of locking the console in
>>          Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
>>          That is, continue using the prepare/resume Idle calls in idle path.
>
> I believe you should be using ->prepare() to prevent that any other
> work on UART won't trigger a console_write() right now. Maybe only
> queueing the work for after ->complete() or, maybe, just ignoring the
> work and loosing some prints, dunno.
>

Yes true, for suspend path but for Idle path we don't have any such
mechanism.

>>       2. Other Approach would be adding conditions to debug prints from
>>          omap_device/ omap_hwmod/clock_framework avoid calling these debug
>>          prints for uart.
>>          Or Even a debug macro that would not debug prints if the context is
>>          from uart.
>
> yeah, that might work but then again, if we were using 8250.c, would we
> have this limitation ??
>

Its not necessary which driver we use, its about clock handling mechanism
where it has to be done.

if we add clock handling mechanism into the driver, from driver context
handling clocks + managing the printks for the same uart port is a
issue, due to reasons said earlier.

> I think that, maybe, your best call would be to capture console_write()
> calls into an internal temporary buffer on ->prepare() and flush it once
> ->complete() is called ?
>

IIUC ->prepare and -> complete are only for suspend path
when we do system wide suspend

for normal idle path get_sync and put_sycn we dont have any ->prepare
or -> complete where we can buffer the contents and flush later.

> BTW, where are the patches ? :-)

I have done clock gating in idle path integrating irq chaining patches.
hosted in gitorious here[1].

Was consolidating whether this approach is OK,
or
Are there any other approaches that I should consider?

--
Thanks,
Govindraj.R

[1]: https://gitorious.org/runtime_3-0/runtime_3-0/commits/wip_irqchn


>
> --
> balbi
>

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Fri, Jul 29, 2011 at 3:25 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>

Thanks for replying.

> On Thu, Jul 28, 2011 at 02:59:55PM +0530, Govindraj.R wrote:
>> Proposal:
>> --------
>>       1. For the UART, follow the current approach of locking the console in
>>          Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
>>          That is, continue using the prepare/resume Idle calls in idle path.
>
> I believe you should be using ->prepare() to prevent that any other
> work on UART won't trigger a console_write() right now. Maybe only
> queueing the work for after ->complete() or, maybe, just ignoring the
> work and loosing some prints, dunno.
>

Yes true, for suspend path but for Idle path we don't have any such
mechanism.

>>       2. Other Approach would be adding conditions to debug prints from
>>          omap_device/ omap_hwmod/clock_framework avoid calling these debug
>>          prints for uart.
>>          Or Even a debug macro that would not debug prints if the context is
>>          from uart.
>
> yeah, that might work but then again, if we were using 8250.c, would we
> have this limitation ??
>

Its not necessary which driver we use, its about clock handling mechanism
where it has to be done.

if we add clock handling mechanism into the driver, from driver context
handling clocks + managing the printks for the same uart port is a
issue, due to reasons said earlier.

> I think that, maybe, your best call would be to capture console_write()
> calls into an internal temporary buffer on ->prepare() and flush it once
> ->complete() is called ?
>

IIUC ->prepare and -> complete are only for suspend path
when we do system wide suspend

for normal idle path get_sync and put_sycn we dont have any ->prepare
or -> complete where we can buffer the contents and flush later.

> BTW, where are the patches ? :-)

I have done clock gating in idle path integrating irq chaining patches.
hosted in gitorious here[1].

Was consolidating whether this approach is OK,
or
Are there any other approaches that I should consider?

--
Thanks,
Govindraj.R

[1]: https://gitorious.org/runtime_3-0/runtime_3-0/commits/wip_irqchn


>
> --
> balbi
>
--
To unsubscribe from this list: send the line "unsubscribe linux-serial" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

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

Hi,

On Fri, Jul 29, 2011 at 04:54:44PM +0530, Govindraj wrote:
> On Fri, Jul 29, 2011 at 3:25 PM, Felipe Balbi <balbi@ti.com> wrote:
> > Hi,
> >
> 
> Thanks for replying.
> 
> > On Thu, Jul 28, 2011 at 02:59:55PM +0530, Govindraj.R wrote:
> >> Proposal:
> >> --------
> >>       1. For the UART, follow the current approach of locking the console in
> >>          Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
> >>          That is, continue using the prepare/resume Idle calls in idle path.
> >
> > I believe you should be using ->prepare() to prevent that any other
> > work on UART won't trigger a console_write() right now. Maybe only
> > queueing the work for after ->complete() or, maybe, just ignoring the
> > work and loosing some prints, dunno.
> >
> 
> Yes true, for suspend path but for Idle path we don't have any such
> mechanism.

aha... good point ;-)

> I have done clock gating in idle path integrating irq chaining patches.
> hosted in gitorious here[1].
> 
> Was consolidating whether this approach is OK,
> or
> Are there any other approaches that I should consider?

why don't you also start queueing writes after the first call to
runtime_suspend() and flush them after the first call runtime_resume()??

-- 
balbi

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

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Fri, Jul 29, 2011 at 5:07 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>
> On Fri, Jul 29, 2011 at 04:54:44PM +0530, Govindraj wrote:
>> On Fri, Jul 29, 2011 at 3:25 PM, Felipe Balbi <balbi@ti.com> wrote:
>> > Hi,
>> >
>>
>> Thanks for replying.
>>
>> > On Thu, Jul 28, 2011 at 02:59:55PM +0530, Govindraj.R wrote:
>> >> Proposal:
>> >> --------
>> >>       1. For the UART, follow the current approach of locking the console in
>> >>          Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
>> >>          That is, continue using the prepare/resume Idle calls in idle path.
>> >
>> > I believe you should be using ->prepare() to prevent that any other
>> > work on UART won't trigger a console_write() right now. Maybe only
>> > queueing the work for after ->complete() or, maybe, just ignoring the
>> > work and loosing some prints, dunno.
>> >
>>
>> Yes true, for suspend path but for Idle path we don't have any such
>> mechanism.
>
> aha... good point ;-)
>
>> I have done clock gating in idle path integrating irq chaining patches.
>> hosted in gitorious here[1].
>>
>> Was consolidating whether this approach is OK,
>> or
>> Are there any other approaches that I should consider?
>
> why don't you also start queueing writes after the first call to
> runtime_suspend() and flush them after the first call runtime_resume()??
>

Yes fine, But there are scenarios even before first runtime_suspend happens,

ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
(omap_device_enable in this case) debug printk -> console_write -> get_sync.

there are numerous such scenarios where we end from runtime context
to runtime api context again, or jumping from one uart port operation
to uart print operation.

So either we should not have those prints from pm_generic layers or suppress
them(seems pretty much a problem for a clean design within the driver
using console_lock/unlock for every get_sync, and for
runtime_put we cannot suppress the prints as it gets scheduled later)

or if other folks who really need those prints form pm_generic* layers
to debug and analysis then we have no other choice rather control
the clk_enable/disable from outside driver code in idle path.

--
Thanks
Govindraj.R

*pm_generic layers for omap, referring to omap_device/omap_hwmod layers
which does low level clock handling.

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Fri, Jul 29, 2011 at 5:07 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>
> On Fri, Jul 29, 2011 at 04:54:44PM +0530, Govindraj wrote:
>> On Fri, Jul 29, 2011 at 3:25 PM, Felipe Balbi <balbi@ti.com> wrote:
>> > Hi,
>> >
>>
>> Thanks for replying.
>>
>> > On Thu, Jul 28, 2011 at 02:59:55PM +0530, Govindraj.R wrote:
>> >> Proposal:
>> >> --------
>> >>       1. For the UART, follow the current approach of locking the console in
>> >>          Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
>> >>          That is, continue using the prepare/resume Idle calls in idle path.
>> >
>> > I believe you should be using ->prepare() to prevent that any other
>> > work on UART won't trigger a console_write() right now. Maybe only
>> > queueing the work for after ->complete() or, maybe, just ignoring the
>> > work and loosing some prints, dunno.
>> >
>>
>> Yes true, for suspend path but for Idle path we don't have any such
>> mechanism.
>
> aha... good point ;-)
>
>> I have done clock gating in idle path integrating irq chaining patches.
>> hosted in gitorious here[1].
>>
>> Was consolidating whether this approach is OK,
>> or
>> Are there any other approaches that I should consider?
>
> why don't you also start queueing writes after the first call to
> runtime_suspend() and flush them after the first call runtime_resume()??
>

Yes fine, But there are scenarios even before first runtime_suspend happens,

ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
(omap_device_enable in this case) debug printk -> console_write -> get_sync.

there are numerous such scenarios where we end from runtime context
to runtime api context again, or jumping from one uart port operation
to uart print operation.

So either we should not have those prints from pm_generic layers or suppress
them(seems pretty much a problem for a clean design within the driver
using console_lock/unlock for every get_sync, and for
runtime_put we cannot suppress the prints as it gets scheduled later)

or if other folks who really need those prints form pm_generic* layers
to debug and analysis then we have no other choice rather control
the clk_enable/disable from outside driver code in idle path.

--
Thanks
Govindraj.R

*pm_generic layers for omap, referring to omap_device/omap_hwmod layers
which does low level clock handling.
--
To unsubscribe from this list: send the line "unsubscribe linux-serial" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

[-- Attachment #1.1: Type: text/plain, Size: 1554 bytes --]

Hi,

On Fri, Jul 29, 2011 at 05:29:12PM +0530, Govindraj wrote:
> Yes fine, But there are scenarios even before first runtime_suspend happens,
> 
> ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
> (omap_device_enable in this case) debug printk -> console_write -> get_sync.
> 
> there are numerous such scenarios where we end from runtime context
> to runtime api context again, or jumping from one uart port operation
> to uart print operation.

calling pm_runtime_get_sync() should not be a problem. It should only
increase the usage counters... This sounds like a race condition on the
driver, no ?

What you're experiencing, if I understood correctly, is a deadlock ? In
that case, can you try to track the locking mechanism on the omap-serial
driver to try to find if there isn't anything obviously wrong ?

> So either we should not have those prints from pm_generic layers or suppress
> them(seems pretty much a problem for a clean design within the driver
> using console_lock/unlock for every get_sync, and for
> runtime_put we cannot suppress the prints as it gets scheduled later)
> 
> or if other folks who really need those prints form pm_generic* layers
> to debug and analysis then we have no other choice rather control
> the clk_enable/disable from outside driver code in idle path.

yeah, none of these would be nice :-(

I think this needs more debugging to be sure what's exactly going on.
What's exactly causing the deadlock ? Which lock is held and never
released ?

-- 
balbi

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

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

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

Hi,

On Fri, Jul 29, 2011 at 05:29:12PM +0530, Govindraj wrote:
> Yes fine, But there are scenarios even before first runtime_suspend happens,
> 
> ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
> (omap_device_enable in this case) debug printk -> console_write -> get_sync.
> 
> there are numerous such scenarios where we end from runtime context
> to runtime api context again, or jumping from one uart port operation
> to uart print operation.

calling pm_runtime_get_sync() should not be a problem. It should only
increase the usage counters... This sounds like a race condition on the
driver, no ?

What you're experiencing, if I understood correctly, is a deadlock ? In
that case, can you try to track the locking mechanism on the omap-serial
driver to try to find if there isn't anything obviously wrong ?

> So either we should not have those prints from pm_generic layers or suppress
> them(seems pretty much a problem for a clean design within the driver
> using console_lock/unlock for every get_sync, and for
> runtime_put we cannot suppress the prints as it gets scheduled later)
> 
> or if other folks who really need those prints form pm_generic* layers
> to debug and analysis then we have no other choice rather control
> the clk_enable/disable from outside driver code in idle path.

yeah, none of these would be nice :-(

I think this needs more debugging to be sure what's exactly going on.
What's exactly causing the deadlock ? Which lock is held and never
released ?

-- 
balbi

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

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Fri, Jul 29, 2011 at 5:49 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>
> On Fri, Jul 29, 2011 at 05:29:12PM +0530, Govindraj wrote:
>> Yes fine, But there are scenarios even before first runtime_suspend happens,
>>
>> ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
>> (omap_device_enable in this case) debug printk -> console_write -> get_sync.
>>
>> there are numerous such scenarios where we end from runtime context
>> to runtime api context again, or jumping from one uart port operation
>> to uart print operation.
>
> calling pm_runtime_get_sync() should not be a problem. It should only
> increase the usage counters... This sounds like a race condition on the
> driver, no ?

Actually when we call a API to enable clocks we except the internals of API
to just enable clocks and return.

*Clock enable API should not cause or trigger to do a _device_driver_operation_
even before enabling clocks of the device-driver which called it*

for uart context get_sync can land me to uart driver back
even before enabling the uart clocks due to printks.

> What you're experiencing, if I understood correctly, is a deadlock ? In
> that case, can you try to track the locking mechanism on the omap-serial
> driver to try to find if there isn't anything obviously wrong ?
>

Yes deadlocks. due to entering from runtime context to runtime context
or entering from uart_port_operation to uart_console_write ops.

There are already port locks used extensively within the uart driver
to secure a port operation.

But cannot secure a port operation while using clock_enable API.
since clock enable API can land the control back to uart_console_write
operation..

>> So either we should not have those prints from pm_generic layers or suppress
>> them(seems pretty much a problem for a clean design within the driver
>> using console_lock/unlock for every get_sync, and for
>> runtime_put we cannot suppress the prints as it gets scheduled later)
>>
>> or if other folks who really need those prints form pm_generic* layers
>> to debug and analysis then we have no other choice rather control
>> the clk_enable/disable from outside driver code in idle path.
>
> yeah, none of these would be nice :-(
>
> I think this needs more debugging to be sure what's exactly going on.
> What's exactly causing the deadlock ? Which lock is held and never
> released ?
>

I had done some investigations, from scenarios it simply boils down to fact
to handle clock within uart driver, uart driver expects clock enable API* used
to just enable uart clocks but rather not trigger a _uart_ops_ within which
kind of unacceptable from the uart_driver context.

--
Thanks,
Govindraj.R


*clock enable API can be any API used to enable clocks like
get_sync/ omap_device_enable/clock_enable etc.

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Fri, Jul 29, 2011 at 5:49 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>
> On Fri, Jul 29, 2011 at 05:29:12PM +0530, Govindraj wrote:
>> Yes fine, But there are scenarios even before first runtime_suspend happens,
>>
>> ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
>> (omap_device_enable in this case) debug printk -> console_write -> get_sync.
>>
>> there are numerous such scenarios where we end from runtime context
>> to runtime api context again, or jumping from one uart port operation
>> to uart print operation.
>
> calling pm_runtime_get_sync() should not be a problem. It should only
> increase the usage counters... This sounds like a race condition on the
> driver, no ?

Actually when we call a API to enable clocks we except the internals of API
to just enable clocks and return.

*Clock enable API should not cause or trigger to do a _device_driver_operation_
even before enabling clocks of the device-driver which called it*

for uart context get_sync can land me to uart driver back
even before enabling the uart clocks due to printks.

> What you're experiencing, if I understood correctly, is a deadlock ? In
> that case, can you try to track the locking mechanism on the omap-serial
> driver to try to find if there isn't anything obviously wrong ?
>

Yes deadlocks. due to entering from runtime context to runtime context
or entering from uart_port_operation to uart_console_write ops.

There are already port locks used extensively within the uart driver
to secure a port operation.

But cannot secure a port operation while using clock_enable API.
since clock enable API can land the control back to uart_console_write
operation..

>> So either we should not have those prints from pm_generic layers or suppress
>> them(seems pretty much a problem for a clean design within the driver
>> using console_lock/unlock for every get_sync, and for
>> runtime_put we cannot suppress the prints as it gets scheduled later)
>>
>> or if other folks who really need those prints form pm_generic* layers
>> to debug and analysis then we have no other choice rather control
>> the clk_enable/disable from outside driver code in idle path.
>
> yeah, none of these would be nice :-(
>
> I think this needs more debugging to be sure what's exactly going on.
> What's exactly causing the deadlock ? Which lock is held and never
> released ?
>

I had done some investigations, from scenarios it simply boils down to fact
to handle clock within uart driver, uart driver expects clock enable API* used
to just enable uart clocks but rather not trigger a _uart_ops_ within which
kind of unacceptable from the uart_driver context.

--
Thanks,
Govindraj.R


*clock enable API can be any API used to enable clocks like
get_sync/ omap_device_enable/clock_enable etc.

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

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

Hi,

On Fri, Jul 29, 2011 at 06:28:32PM +0530, Govindraj wrote:
> On Fri, Jul 29, 2011 at 5:49 PM, Felipe Balbi <balbi@ti.com> wrote:
> > On Fri, Jul 29, 2011 at 05:29:12PM +0530, Govindraj wrote:
> >> Yes fine, But there are scenarios even before first runtime_suspend happens,
> >>
> >> ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
> >> (omap_device_enable in this case) debug printk -> console_write -> get_sync.
> >>
> >> there are numerous such scenarios where we end from runtime context
> >> to runtime api context again, or jumping from one uart port operation
> >> to uart print operation.
> >
> > calling pm_runtime_get_sync() should not be a problem. It should only
> > increase the usage counters... This sounds like a race condition on the
> > driver, no ?
> 
> Actually when we call a API to enable clocks we except the internals of API
> to just enable clocks and return.
> 
> *Clock enable API should not cause or trigger to do a _device_driver_operation_
> even before enabling clocks of the device-driver which called it*
> 
> for uart context get_sync can land me to uart driver back
> even before enabling the uart clocks due to printks.

only if _you_ have prints or _your_ runtime_*() calls, no ?

Let's say omap_hwmod.c wants to do a print:

-> printk()
  -> pm_runtime_get_sync
    -> console_write
  -> pm_runtim_put

now, if you have a printk() on your runtime_resume() before you enable
the clocks, then I can see why you would deadlock:

-> pm_runtime_get_sync
  -> omap_serial_runtime_resume
    -> printk
      -> pm_runtime_get_sync
        -> omap_serial_runtime_resume
	  -> printk
	   -> pm_runtime_get_sync
	    .....

maybe I'm missing something, but can you add a stack dump on your
->runtime_resume and ->runtime_suspend methods, just so we try to figure
out who's to blame here ?

> > What you're experiencing, if I understood correctly, is a deadlock ? In
> > that case, can you try to track the locking mechanism on the omap-serial
> > driver to try to find if there isn't anything obviously wrong ?
> >
> 
> Yes deadlocks. due to entering from runtime context to runtime context
> or entering from uart_port_operation to uart_console_write ops.
> 
> There are already port locks used extensively within the uart driver
> to secure a port operation.
> 
> But cannot secure a port operation while using clock_enable API.
> since clock enable API can land the control back to uart_console_write
> operation..

but in that case, if clock isn't enabled, why don't you just ignore the
print and enable the clock ?? Just return 0 and continue with
clk_enable() ??

> >> So either we should not have those prints from pm_generic layers or suppress
> >> them(seems pretty much a problem for a clean design within the driver
> >> using console_lock/unlock for every get_sync, and for
> >> runtime_put we cannot suppress the prints as it gets scheduled later)
> >>
> >> or if other folks who really need those prints form pm_generic* layers
> >> to debug and analysis then we have no other choice rather control
> >> the clk_enable/disable from outside driver code in idle path.
> >
> > yeah, none of these would be nice :-(
> >
> > I think this needs more debugging to be sure what's exactly going on.
> > What's exactly causing the deadlock ? Which lock is held and never
> > released ?
> >
> 
> I had done some investigations, from scenarios it simply boils down to fact
> to handle clock within uart driver, uart driver expects clock enable API* used
> to just enable uart clocks but rather not trigger a _uart_ops_ within which
> kind of unacceptable from the uart_driver context.

ok, now I see what you mean:

113 static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
114 {
115         struct timespec a, b, c;
116
117         pr_debug("omap_device: %s: activating\n", od->pdev.name);
118
119         while (od->pm_lat_level > 0) {
120                 struct omap_device_pm_latency *odpl;
121                 unsigned long long act_lat = 0;
122
123                 od->pm_lat_level--;
124
125                 odpl = od->pm_lats + od->pm_lat_level;
126
127                 if (!ignore_lat &&
128                     (od->dev_wakeup_lat <= od->_dev_wakeup_lat_limit))
129                         break;
130
131                 read_persistent_clock(&a);
132
133                 /* XXX check return code */
134                 odpl->activate_func(od);
135
136                 read_persistent_clock(&b);
137
138                 c = timespec_sub(b, a);
139                 act_lat = timespec_to_ns(&c);
140
141                 pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
142                          "%llu nsec\n", od->pdev.name, od->pm_lat_level,
143                          act_lat);
144
145                 if (act_lat > odpl->activate_lat) {
146                         odpl->activate_lat_worst = act_lat;
147                         if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
148                                 odpl->activate_lat = act_lat;
149                                 pr_warning("omap_device: %s.%d: new worst case "
150                                            "activate latency %d: %llu\n",
151                                            od->pdev.name, od->pdev.id,
152                                            od->pm_lat_level, act_lat);
153                         } else
154                                 pr_warning("omap_device: %s.%d: activate "
155                                            "latency %d higher than exptected. "
156                                            "(%llu > %d)\n",
157                                            od->pdev.name, od->pdev.id,
158                                            od->pm_lat_level, act_lat,
159                                            odpl->activate_lat);
160                 }
161
162                 od->dev_wakeup_lat -= odpl->activate_lat;
163         }
164
165         return 0;
166 }

When that first pr_debug() triggers, UART's hwmod could be disabled, and
that would trigger the state I described above where you would keep on
calling pm_runtime_get_sync() forever ;-)

isn't it enough to patch it like below:

diff --git a/arch/arm/plat-omap/omap_device.c b/arch/arm/plat-omap/omap_device.c
index b6b4097..560f622 100644
--- a/arch/arm/plat-omap/omap_device.c
+++ b/arch/arm/plat-omap/omap_device.c
@@ -114,8 +114,6 @@ static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
 {
        struct timespec a, b, c;
 
-       pr_debug("omap_device: %s: activating\n", od->pdev.name);
-
        while (od->pm_lat_level > 0) {
                struct omap_device_pm_latency *odpl;
                unsigned long long act_lat = 0;
@@ -162,6 +160,8 @@ static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
                od->dev_wakeup_lat -= odpl->activate_lat;
        }
 
+       pr_debug("omap_device: %s: activated\n", od->pdev.name);
+
        return 0;
 }
 

either the above or something like:

if (pm_runtime_suspended(dev))
	return 0;

on console_write() ??

-- 
balbi

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

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Fri, Jul 29, 2011 at 7:32 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>
> On Fri, Jul 29, 2011 at 06:28:32PM +0530, Govindraj wrote:
>> On Fri, Jul 29, 2011 at 5:49 PM, Felipe Balbi <balbi@ti.com> wrote:
>> > On Fri, Jul 29, 2011 at 05:29:12PM +0530, Govindraj wrote:
>> >> Yes fine, But there are scenarios even before first runtime_suspend happens,
>> >>
>> >> ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
>> >> (omap_device_enable in this case) debug printk -> console_write -> get_sync.
>> >>
>> >> there are numerous such scenarios where we end from runtime context
>> >> to runtime api context again, or jumping from one uart port operation
>> >> to uart print operation.
>> >
>> > calling pm_runtime_get_sync() should not be a problem. It should only
>> > increase the usage counters... This sounds like a race condition on the
>> > driver, no ?
>>
>> Actually when we call a API to enable clocks we except the internals of API
>> to just enable clocks and return.
>>
>> *Clock enable API should not cause or trigger to do a _device_driver_operation_
>> even before enabling clocks of the device-driver which called it*
>>
>> for uart context get_sync can land me to uart driver back
>> even before enabling the uart clocks due to printks.
>
> only if _you_ have prints or _your_ runtime_*() calls, no ?
>
> Let's say omap_hwmod.c wants to do a print:
>
> -> printk()
>  -> pm_runtime_get_sync
>    -> console_write
>  -> pm_runtim_put
>
> now, if you have a printk() on your runtime_resume() before you enable
> the clocks, then I can see why you would deadlock:
>
> -> pm_runtime_get_sync
>  -> omap_serial_runtime_resume
>    -> printk
>      -> pm_runtime_get_sync
>        -> omap_serial_runtime_resume
>          -> printk
>           -> pm_runtime_get_sync
>            .....
>
> maybe I'm missing something, but can you add a stack dump on your
> ->runtime_resume and ->runtime_suspend methods, just so we try to figure
> out who's to blame here ?
>
>> > What you're experiencing, if I understood correctly, is a deadlock ? In
>> > that case, can you try to track the locking mechanism on the omap-serial
>> > driver to try to find if there isn't anything obviously wrong ?
>> >
>>
>> Yes deadlocks. due to entering from runtime context to runtime context
>> or entering from uart_port_operation to uart_console_write ops.
>>
>> There are already port locks used extensively within the uart driver
>> to secure a port operation.
>>
>> But cannot secure a port operation while using clock_enable API.
>> since clock enable API can land the control back to uart_console_write
>> operation..
>
> but in that case, if clock isn't enabled, why don't you just ignore the
> print and enable the clock ?? Just return 0 and continue with
> clk_enable() ??
>
>> >> So either we should not have those prints from pm_generic layers or suppress
>> >> them(seems pretty much a problem for a clean design within the driver
>> >> using console_lock/unlock for every get_sync, and for
>> >> runtime_put we cannot suppress the prints as it gets scheduled later)
>> >>
>> >> or if other folks who really need those prints form pm_generic* layers
>> >> to debug and analysis then we have no other choice rather control
>> >> the clk_enable/disable from outside driver code in idle path.
>> >
>> > yeah, none of these would be nice :-(
>> >
>> > I think this needs more debugging to be sure what's exactly going on.
>> > What's exactly causing the deadlock ? Which lock is held and never
>> > released ?
>> >
>>
>> I had done some investigations, from scenarios it simply boils down to fact
>> to handle clock within uart driver, uart driver expects clock enable API* used
>> to just enable uart clocks but rather not trigger a _uart_ops_ within which
>> kind of unacceptable from the uart_driver context.
>
> ok, now I see what you mean:
>
> 113 static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
> 114 {
> 115         struct timespec a, b, c;
> 116
> 117         pr_debug("omap_device: %s: activating\n", od->pdev.name);
> 118
> 119         while (od->pm_lat_level > 0) {
> 120                 struct omap_device_pm_latency *odpl;
> 121                 unsigned long long act_lat = 0;
> 122
> 123                 od->pm_lat_level--;
> 124
> 125                 odpl = od->pm_lats + od->pm_lat_level;
> 126
> 127                 if (!ignore_lat &&
> 128                     (od->dev_wakeup_lat <= od->_dev_wakeup_lat_limit))
> 129                         break;
> 130
> 131                 read_persistent_clock(&a);
> 132
> 133                 /* XXX check return code */
> 134                 odpl->activate_func(od);
> 135
> 136                 read_persistent_clock(&b);
> 137
> 138                 c = timespec_sub(b, a);
> 139                 act_lat = timespec_to_ns(&c);
> 140
> 141                 pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
> 142                          "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> 143                          act_lat);
> 144
> 145                 if (act_lat > odpl->activate_lat) {
> 146                         odpl->activate_lat_worst = act_lat;
> 147                         if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
> 148                                 odpl->activate_lat = act_lat;
> 149                                 pr_warning("omap_device: %s.%d: new worst case "
> 150                                            "activate latency %d: %llu\n",
> 151                                            od->pdev.name, od->pdev.id,
> 152                                            od->pm_lat_level, act_lat);
> 153                         } else
> 154                                 pr_warning("omap_device: %s.%d: activate "
> 155                                            "latency %d higher than exptected. "
> 156                                            "(%llu > %d)\n",
> 157                                            od->pdev.name, od->pdev.id,
> 158                                            od->pm_lat_level, act_lat,
> 159                                            odpl->activate_lat);
> 160                 }
> 161
> 162                 od->dev_wakeup_lat -= odpl->activate_lat;
> 163         }
> 164
> 165         return 0;
> 166 }
>
> When that first pr_debug() triggers, UART's hwmod could be disabled, and
> that would trigger the state I described above where you would keep on
> calling pm_runtime_get_sync() forever ;-)
>
> isn't it enough to patch it like below:
>
> diff --git a/arch/arm/plat-omap/omap_device.c b/arch/arm/plat-omap/omap_device.c
> index b6b4097..560f622 100644
> --- a/arch/arm/plat-omap/omap_device.c
> +++ b/arch/arm/plat-omap/omap_device.c
> @@ -114,8 +114,6 @@ static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
>  {
>        struct timespec a, b, c;
>
> -       pr_debug("omap_device: %s: activating\n", od->pdev.name);
> -
>        while (od->pm_lat_level > 0) {
>                struct omap_device_pm_latency *odpl;
>                unsigned long long act_lat = 0;
> @@ -162,6 +160,8 @@ static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
>                od->dev_wakeup_lat -= odpl->activate_lat;
>        }
>
> +       pr_debug("omap_device: %s: activated\n", od->pdev.name);
> +
>        return 0;
>  }
>

Actually there is much more than this:

<<SNIP>>

diff --git a/arch/arm/mach-omap2/clock.c b/arch/arm/mach-omap2/clock.c
index 180299e..221ffb9 100644
--- a/arch/arm/mach-omap2/clock.c
+++ b/arch/arm/mach-omap2/clock.c
@@ -12,7 +12,8 @@
  * it under the terms of the GNU General Public License version 2 as
  * published by the Free Software Foundation.
  */
-#undef DEBUG
+//#undef DEBUG
+#define DEBUG

 #include <linux/kernel.h>
 #include <linux/list.h>
@@ -254,14 +255,14 @@ void omap2_clk_disable(struct clk *clk)
 		return;
 	}

-	pr_debug("clock: %s: decrementing usecount\n", clk->name);
+//	pr_debug("clock: %s: decrementing usecount\n", clk->name);

 	clk->usecount--;

 	if (clk->usecount > 0)
 		return;

-	pr_debug("clock: %s: disabling in hardware\n", clk->name);
+//	pr_debug("clock: %s: disabling in hardware\n", clk->name);

 	if (clk->ops && clk->ops->disable) {
 		trace_clock_disable(clk->name, 0, smp_processor_id());
@@ -290,14 +291,14 @@ int omap2_clk_enable(struct clk *clk)
 {
 	int ret;

-	pr_debug("clock: %s: incrementing usecount\n", clk->name);
+//	pr_debug("clock: %s: incrementing usecount\n", clk->name);

 	clk->usecount++;

 	if (clk->usecount > 1)
 		return 0;

-	pr_debug("clock: %s: enabling in hardware\n", clk->name);
+//	pr_debug("clock: %s: enabling in hardware\n", clk->name);

 	if (clk->parent) {
 		ret = omap2_clk_enable(clk->parent);
diff --git a/arch/arm/mach-omap2/omap_hwmod.c b/arch/arm/mach-omap2/omap_hwmod.c
index 7ed0479..8ca7d40 100644
--- a/arch/arm/mach-omap2/omap_hwmod.c
+++ b/arch/arm/mach-omap2/omap_hwmod.c
@@ -124,7 +124,8 @@
  * XXX error return values should be checked to ensure that they are
  * appropriate
  */
-#undef DEBUG
+//#undef DEBUG
+#define DEBUG

 #include <linux/kernel.h>
 #include <linux/errno.h>
@@ -597,7 +598,8 @@ static int _enable_clocks(struct omap_hwmod *oh)
 {
 	int i;

-	pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
+	if (strcmp(oh->class->name, "uart"))
+		pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);

 	if (oh->_clk)
 		clk_enable(oh->_clk);
@@ -627,7 +629,8 @@ static int _disable_clocks(struct omap_hwmod *oh)
 {
 	int i;

-	pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
+	if (strcmp(oh->class->name, "uart"))
+		pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);

 	if (oh->_clk)
 		clk_disable(oh->_clk);
@@ -1232,7 +1235,8 @@ static int _enable(struct omap_hwmod *oh)
 		return -EINVAL;
 	}

-	pr_debug("omap_hwmod: %s: enabling\n", oh->name);
+	if (strcmp(oh->class->name, "uart"))
+		pr_debug("omap_hwmod: %s: enabling\n", oh->name);

 	/*
 	 * If an IP contains only one HW reset line, then de-assert it in order
@@ -1264,8 +1268,9 @@ static int _enable(struct omap_hwmod *oh)
 		}
 	} else {
 		_disable_clocks(oh);
-		pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
-			 oh->name, r);
+		if (strcmp(oh->class->name, "uart"))
+			pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
+				 oh->name, r);
 	}

 	return r;
@@ -1287,7 +1292,8 @@ static int _idle(struct omap_hwmod *oh)
 		return -EINVAL;
 	}

-	pr_debug("omap_hwmod: %s: idling\n", oh->name);
+	if (strcmp(oh->class->name, "uart"))
+		pr_debug("omap_hwmod: %s: idling\n", oh->name);

 	if (oh->class->sysc)
 		_idle_sysc(oh);
diff --git a/arch/arm/plat-omap/omap_device.c b/arch/arm/plat-omap/omap_device.c
index 49fc0df..7b27704 100644
--- a/arch/arm/plat-omap/omap_device.c
+++ b/arch/arm/plat-omap/omap_device.c
@@ -75,7 +75,8 @@
  * (device must be reinitialized at this point to use it again)
  *
  */
-#undef DEBUG
+//#undef DEBUG
+#define DEBUG

 #include <linux/kernel.h>
 #include <linux/platform_device.h>
@@ -114,7 +115,8 @@ static int _omap_device_activate(struct
omap_device *od, u8 ignore_lat)
 {
 	struct timespec a, b, c;

-	pr_debug("omap_device: %s: activating\n", od->pdev.name);
+	if (strcmp(od->hwmods[0]->class->name, "uart"))
+		pr_debug("omap_device: %s: activating\n", od->pdev.name);

 	while (od->pm_lat_level > 0) {
 		struct omap_device_pm_latency *odpl;
@@ -138,25 +140,29 @@ static int _omap_device_activate(struct
omap_device *od, u8 ignore_lat)
 		c = timespec_sub(b, a);
 		act_lat = timespec_to_ns(&c);

-		pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
-			 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
-			 act_lat);
+		if (strcmp(od->hwmods[0]->class->name, "uart"))
+			pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
+				 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
+				 act_lat);

 		if (act_lat > odpl->activate_lat) {
 			odpl->activate_lat_worst = act_lat;
 			if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
 				odpl->activate_lat = act_lat;
-				pr_warning("omap_device: %s.%d: new worst case "
-					   "activate latency %d: %llu\n",
-					   od->pdev.name, od->pdev.id,
-					   od->pm_lat_level, act_lat);
-			} else
-				pr_warning("omap_device: %s.%d: activate "
-					   "latency %d higher than exptected. "
-					   "(%llu > %d)\n",
-					   od->pdev.name, od->pdev.id,
-					   od->pm_lat_level, act_lat,
-					   odpl->activate_lat);
+				if (strcmp(od->hwmods[0]->class->name, "uart"))
+					pr_warning("omap_device: %s.%d: new worst case "
+						"activate latency %d: %llu\n",
+						od->pdev.name, od->pdev.id,
+						od->pm_lat_level, act_lat);
+			} else {
+				if (strcmp(od->hwmods[0]->class->name, "uart"))
+					pr_warning("omap_device: %s.%d: activate "
+						"latency %d higher than exptected. "
+						"(%llu > %d)\n",
+						od->pdev.name, od->pdev.id,
+						od->pm_lat_level, act_lat,
+						odpl->activate_lat);
+			}
 		}

 		od->dev_wakeup_lat -= odpl->activate_lat;
@@ -183,7 +189,8 @@ static int _omap_device_deactivate(struct
omap_device *od, u8 ignore_lat)
 {
 	struct timespec a, b, c;

-	pr_debug("omap_device: %s: deactivating\n", od->pdev.name);
+	if (strcmp(od->hwmods[0]->class->name, "uart"))
+		pr_debug("omap_device: %s: deactivating\n", od->pdev.name);

 	while (od->pm_lat_level < od->pm_lats_cnt) {
 		struct omap_device_pm_latency *odpl;
@@ -206,25 +213,29 @@ static int _omap_device_deactivate(struct
omap_device *od, u8 ignore_lat)
 		c = timespec_sub(b, a);
 		deact_lat = timespec_to_ns(&c);

-		pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed time "
-			 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
-			 deact_lat);
+		if (strcmp(od->hwmods[0]->class->name, "uart"))
+			pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed time "
+				 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
+				 deact_lat);

 		if (deact_lat > odpl->deactivate_lat) {
 			odpl->deactivate_lat_worst = deact_lat;
 			if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
 				odpl->deactivate_lat = deact_lat;
-				pr_warning("omap_device: %s.%d: new worst case "
-					   "deactivate latency %d: %llu\n",
-					   od->pdev.name, od->pdev.id,
-					   od->pm_lat_level, deact_lat);
-			} else
-				pr_warning("omap_device: %s.%d: deactivate "
+				if (strcmp(od->hwmods[0]->class->name, "uart"))
+					pr_warning("omap_device: %s.%d: new worst case "
+						   "deactivate latency %d: %llu\n",
+						   od->pdev.name, od->pdev.id,
+						   od->pm_lat_level, deact_lat);
+			} else {
+				if (strcmp(od->hwmods[0]->class->name, "uart"))
+					pr_warning("omap_device: %s.%d: deactivate "
 					   "latency %d higher than exptected. "
 					   "(%llu > %d)\n",
 					   od->pdev.name, od->pdev.id,
 					   od->pm_lat_level, deact_lat,
 					   odpl->deactivate_lat);
+			}
 		}


<<SNIP>>


>
> either the above or something like:
>
> if (pm_runtime_suspended(dev))
>        return 0;
>
> on console_write() ??

Consider the scenario where after bootup uart is idled
with runtime auto suspend so now state of console
uart is RPM_SUSPENDED.

Now you connect a pendrive to ehci-port.

Missing critical usb host <-> device_enumeration prints?

uart_console rpm_suspended state ->

usb_device mass storage device found print ->

console_write -> return without printing.

--
Thanks,
Govindraj.R
--
To unsubscribe from this list: send the line "unsubscribe linux-omap" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

[-- Attachment #1.1: Type: text/plain, Size: 8335 bytes --]

Hi,

On Fri, Jul 29, 2011 at 08:43:49PM +0530, Govindraj wrote:

[giant snip]

> Actually there is much more than this:
> 
> <<SNIP>>
> 
> diff --git a/arch/arm/mach-omap2/clock.c b/arch/arm/mach-omap2/clock.c
> index 180299e..221ffb9 100644
> --- a/arch/arm/mach-omap2/clock.c
> +++ b/arch/arm/mach-omap2/clock.c
> @@ -12,7 +12,8 @@
>   * it under the terms of the GNU General Public License version 2 as
>   * published by the Free Software Foundation.
>   */
> -#undef DEBUG
> +//#undef DEBUG
> +#define DEBUG

trailing... but you know that :-p

> @@ -254,14 +255,14 @@ void omap2_clk_disable(struct clk *clk)
>  		return;
>  	}
> 
> -	pr_debug("clock: %s: decrementing usecount\n", clk->name);
> +//	pr_debug("clock: %s: decrementing usecount\n", clk->name);
> 
>  	clk->usecount--;
> 
>  	if (clk->usecount > 0)
>  		return;
> 
> -	pr_debug("clock: %s: disabling in hardware\n", clk->name);
> +//	pr_debug("clock: %s: disabling in hardware\n", clk->name);
> 
>  	if (clk->ops && clk->ops->disable) {
>  		trace_clock_disable(clk->name, 0, smp_processor_id());

this hunk is unnecessary. Clocks are always on when they are called.

> @@ -290,14 +291,14 @@ int omap2_clk_enable(struct clk *clk)
>  {
>  	int ret;
> 
> -	pr_debug("clock: %s: incrementing usecount\n", clk->name);
> +//	pr_debug("clock: %s: incrementing usecount\n", clk->name);
> 
>  	clk->usecount++;
> 
>  	if (clk->usecount > 1)
>  		return 0;
> 
> -	pr_debug("clock: %s: enabling in hardware\n", clk->name);
> +//	pr_debug("clock: %s: enabling in hardware\n", clk->name);

these two is ok.

> diff --git a/arch/arm/mach-omap2/omap_hwmod.c b/arch/arm/mach-omap2/omap_hwmod.c
> index 7ed0479..8ca7d40 100644
> --- a/arch/arm/mach-omap2/omap_hwmod.c
> +++ b/arch/arm/mach-omap2/omap_hwmod.c
> @@ -124,7 +124,8 @@
>   * XXX error return values should be checked to ensure that they are
>   * appropriate
>   */
> -#undef DEBUG
> +//#undef DEBUG
> +#define DEBUG

trailing.

> @@ -597,7 +598,8 @@ static int _enable_clocks(struct omap_hwmod *oh)
>  {
>  	int i;
> 
> -	pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
> +	if (strcmp(oh->class->name, "uart"))
> +		pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);

instead of doing checks, you could move the print to the end of the
function, when clocks are already enabled. When doind that, of course,
update the comment to say "%s: clocks enabled\n".

> @@ -627,7 +629,8 @@ static int _disable_clocks(struct omap_hwmod *oh)
>  {
>  	int i;
> 
> -	pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
> +	if (strcmp(oh->class->name, "uart"))
> +		pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);

check not needed, clocks are still on.

> 
>  	if (oh->_clk)
>  		clk_disable(oh->_clk);
> @@ -1232,7 +1235,8 @@ static int _enable(struct omap_hwmod *oh)
>  		return -EINVAL;
>  	}
> 
> -	pr_debug("omap_hwmod: %s: enabling\n", oh->name);
> +	if (strcmp(oh->class->name, "uart"))
> +		pr_debug("omap_hwmod: %s: enabling\n", oh->name);

move it further down.

> @@ -1264,8 +1268,9 @@ static int _enable(struct omap_hwmod *oh)
>  		}
>  	} else {
>  		_disable_clocks(oh);
> -		pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
> -			 oh->name, r);
> +		if (strcmp(oh->class->name, "uart"))
> +			pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
> +				 oh->name, r);

instead of adding check, move the print before _disable_clocks(oh).

> @@ -1287,7 +1292,8 @@ static int _idle(struct omap_hwmod *oh)
>  		return -EINVAL;
>  	}
> 
> -	pr_debug("omap_hwmod: %s: idling\n", oh->name);
> +	if (strcmp(oh->class->name, "uart"))
> +		pr_debug("omap_hwmod: %s: idling\n", oh->name);

I believe clocks are still on here too, no checks needed.

> diff --git a/arch/arm/plat-omap/omap_device.c b/arch/arm/plat-omap/omap_device.c
> index 49fc0df..7b27704 100644
> --- a/arch/arm/plat-omap/omap_device.c
> +++ b/arch/arm/plat-omap/omap_device.c
> @@ -75,7 +75,8 @@
>   * (device must be reinitialized at this point to use it again)
>   *
>   */
> -#undef DEBUG
> +//#undef DEBUG
> +#define DEBUG

trailing.

> @@ -114,7 +115,8 @@ static int _omap_device_activate(struct
> omap_device *od, u8 ignore_lat)
>  {
>  	struct timespec a, b, c;
> 
> -	pr_debug("omap_device: %s: activating\n", od->pdev.name);
> +	if (strcmp(od->hwmods[0]->class->name, "uart"))
> +		pr_debug("omap_device: %s: activating\n", od->pdev.name);

move it to the end of the function.

> @@ -138,25 +140,29 @@ static int _omap_device_activate(struct
> omap_device *od, u8 ignore_lat)
>  		c = timespec_sub(b, a);
>  		act_lat = timespec_to_ns(&c);
> 
> -		pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
> -			 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> -			 act_lat);
> +		if (strcmp(od->hwmods[0]->class->name, "uart"))
> +			pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
> +				 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> +				 act_lat);

move it further down.

> 
>  		if (act_lat > odpl->activate_lat) {
>  			odpl->activate_lat_worst = act_lat;
>  			if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
>  				odpl->activate_lat = act_lat;
> -				pr_warning("omap_device: %s.%d: new worst case "
> -					   "activate latency %d: %llu\n",
> -					   od->pdev.name, od->pdev.id,
> -					   od->pm_lat_level, act_lat);
> -			} else
> -				pr_warning("omap_device: %s.%d: activate "
> -					   "latency %d higher than exptected. "
> -					   "(%llu > %d)\n",
> -					   od->pdev.name, od->pdev.id,
> -					   od->pm_lat_level, act_lat,
> -					   odpl->activate_lat);
> +				if (strcmp(od->hwmods[0]->class->name, "uart"))
> +					pr_warning("omap_device: %s.%d: new worst case "
> +						"activate latency %d: %llu\n",
> +						od->pdev.name, od->pdev.id,
> +						od->pm_lat_level, act_lat);
> +			} else {
> +				if (strcmp(od->hwmods[0]->class->name, "uart"))
> +					pr_warning("omap_device: %s.%d: activate "
> +						"latency %d higher than exptected. "
> +						"(%llu > %d)\n",
> +						od->pdev.name, od->pdev.id,
> +						od->pm_lat_level, act_lat,
> +						odpl->activate_lat);

->activate_func() has already been called here, clocks are already on.

> @@ -183,7 +189,8 @@ static int _omap_device_deactivate(struct
> omap_device *od, u8 ignore_lat)
>  {
>  	struct timespec a, b, c;
> 
> -	pr_debug("omap_device: %s: deactivating\n", od->pdev.name);
> +	if (strcmp(od->hwmods[0]->class->name, "uart"))
> +		pr_debug("omap_device: %s: deactivating\n", od->pdev.name);

clocks are still on here.

> @@ -206,25 +213,29 @@ static int _omap_device_deactivate(struct
> omap_device *od, u8 ignore_lat)
>  		c = timespec_sub(b, a);
>  		deact_lat = timespec_to_ns(&c);
> 
> -		pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed time "
> -			 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> -			 deact_lat);
> +		if (strcmp(od->hwmods[0]->class->name, "uart"))
> +			pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed time "
> +				 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> +				 deact_lat);

I'll leave this to Kevin to decide what to do, but clocks are off
here...

>  		if (deact_lat > odpl->deactivate_lat) {
>  			odpl->deactivate_lat_worst = deact_lat;
>  			if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
>  				odpl->deactivate_lat = deact_lat;
> -				pr_warning("omap_device: %s.%d: new worst case "
> -					   "deactivate latency %d: %llu\n",
> -					   od->pdev.name, od->pdev.id,
> -					   od->pm_lat_level, deact_lat);
> -			} else
> -				pr_warning("omap_device: %s.%d: deactivate "
> +				if (strcmp(od->hwmods[0]->class->name, "uart"))
> +					pr_warning("omap_device: %s.%d: new worst case "
> +						   "deactivate latency %d: %llu\n",
> +						   od->pdev.name, od->pdev.id,
> +						   od->pm_lat_level, deact_lat);
> +			} else {
> +				if (strcmp(od->hwmods[0]->class->name, "uart"))
> +					pr_warning("omap_device: %s.%d: deactivate "
>  					   "latency %d higher than exptected. "
>  					   "(%llu > %d)\n",
>  					   od->pdev.name, od->pdev.id,
>  					   od->pm_lat_level, deact_lat,
>  					   odpl->deactivate_lat);
> +			}

and here...

-- 
balbi

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

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

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

Hi,

On Fri, Jul 29, 2011 at 08:43:49PM +0530, Govindraj wrote:

[giant snip]

> Actually there is much more than this:
> 
> <<SNIP>>
> 
> diff --git a/arch/arm/mach-omap2/clock.c b/arch/arm/mach-omap2/clock.c
> index 180299e..221ffb9 100644
> --- a/arch/arm/mach-omap2/clock.c
> +++ b/arch/arm/mach-omap2/clock.c
> @@ -12,7 +12,8 @@
>   * it under the terms of the GNU General Public License version 2 as
>   * published by the Free Software Foundation.
>   */
> -#undef DEBUG
> +//#undef DEBUG
> +#define DEBUG

trailing... but you know that :-p

> @@ -254,14 +255,14 @@ void omap2_clk_disable(struct clk *clk)
>  		return;
>  	}
> 
> -	pr_debug("clock: %s: decrementing usecount\n", clk->name);
> +//	pr_debug("clock: %s: decrementing usecount\n", clk->name);
> 
>  	clk->usecount--;
> 
>  	if (clk->usecount > 0)
>  		return;
> 
> -	pr_debug("clock: %s: disabling in hardware\n", clk->name);
> +//	pr_debug("clock: %s: disabling in hardware\n", clk->name);
> 
>  	if (clk->ops && clk->ops->disable) {
>  		trace_clock_disable(clk->name, 0, smp_processor_id());

this hunk is unnecessary. Clocks are always on when they are called.

> @@ -290,14 +291,14 @@ int omap2_clk_enable(struct clk *clk)
>  {
>  	int ret;
> 
> -	pr_debug("clock: %s: incrementing usecount\n", clk->name);
> +//	pr_debug("clock: %s: incrementing usecount\n", clk->name);
> 
>  	clk->usecount++;
> 
>  	if (clk->usecount > 1)
>  		return 0;
> 
> -	pr_debug("clock: %s: enabling in hardware\n", clk->name);
> +//	pr_debug("clock: %s: enabling in hardware\n", clk->name);

these two is ok.

> diff --git a/arch/arm/mach-omap2/omap_hwmod.c b/arch/arm/mach-omap2/omap_hwmod.c
> index 7ed0479..8ca7d40 100644
> --- a/arch/arm/mach-omap2/omap_hwmod.c
> +++ b/arch/arm/mach-omap2/omap_hwmod.c
> @@ -124,7 +124,8 @@
>   * XXX error return values should be checked to ensure that they are
>   * appropriate
>   */
> -#undef DEBUG
> +//#undef DEBUG
> +#define DEBUG

trailing.

> @@ -597,7 +598,8 @@ static int _enable_clocks(struct omap_hwmod *oh)
>  {
>  	int i;
> 
> -	pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
> +	if (strcmp(oh->class->name, "uart"))
> +		pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);

instead of doing checks, you could move the print to the end of the
function, when clocks are already enabled. When doind that, of course,
update the comment to say "%s: clocks enabled\n".

> @@ -627,7 +629,8 @@ static int _disable_clocks(struct omap_hwmod *oh)
>  {
>  	int i;
> 
> -	pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
> +	if (strcmp(oh->class->name, "uart"))
> +		pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);

check not needed, clocks are still on.

> 
>  	if (oh->_clk)
>  		clk_disable(oh->_clk);
> @@ -1232,7 +1235,8 @@ static int _enable(struct omap_hwmod *oh)
>  		return -EINVAL;
>  	}
> 
> -	pr_debug("omap_hwmod: %s: enabling\n", oh->name);
> +	if (strcmp(oh->class->name, "uart"))
> +		pr_debug("omap_hwmod: %s: enabling\n", oh->name);

move it further down.

> @@ -1264,8 +1268,9 @@ static int _enable(struct omap_hwmod *oh)
>  		}
>  	} else {
>  		_disable_clocks(oh);
> -		pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
> -			 oh->name, r);
> +		if (strcmp(oh->class->name, "uart"))
> +			pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
> +				 oh->name, r);

instead of adding check, move the print before _disable_clocks(oh).

> @@ -1287,7 +1292,8 @@ static int _idle(struct omap_hwmod *oh)
>  		return -EINVAL;
>  	}
> 
> -	pr_debug("omap_hwmod: %s: idling\n", oh->name);
> +	if (strcmp(oh->class->name, "uart"))
> +		pr_debug("omap_hwmod: %s: idling\n", oh->name);

I believe clocks are still on here too, no checks needed.

> diff --git a/arch/arm/plat-omap/omap_device.c b/arch/arm/plat-omap/omap_device.c
> index 49fc0df..7b27704 100644
> --- a/arch/arm/plat-omap/omap_device.c
> +++ b/arch/arm/plat-omap/omap_device.c
> @@ -75,7 +75,8 @@
>   * (device must be reinitialized at this point to use it again)
>   *
>   */
> -#undef DEBUG
> +//#undef DEBUG
> +#define DEBUG

trailing.

> @@ -114,7 +115,8 @@ static int _omap_device_activate(struct
> omap_device *od, u8 ignore_lat)
>  {
>  	struct timespec a, b, c;
> 
> -	pr_debug("omap_device: %s: activating\n", od->pdev.name);
> +	if (strcmp(od->hwmods[0]->class->name, "uart"))
> +		pr_debug("omap_device: %s: activating\n", od->pdev.name);

move it to the end of the function.

> @@ -138,25 +140,29 @@ static int _omap_device_activate(struct
> omap_device *od, u8 ignore_lat)
>  		c = timespec_sub(b, a);
>  		act_lat = timespec_to_ns(&c);
> 
> -		pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
> -			 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> -			 act_lat);
> +		if (strcmp(od->hwmods[0]->class->name, "uart"))
> +			pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
> +				 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> +				 act_lat);

move it further down.

> 
>  		if (act_lat > odpl->activate_lat) {
>  			odpl->activate_lat_worst = act_lat;
>  			if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
>  				odpl->activate_lat = act_lat;
> -				pr_warning("omap_device: %s.%d: new worst case "
> -					   "activate latency %d: %llu\n",
> -					   od->pdev.name, od->pdev.id,
> -					   od->pm_lat_level, act_lat);
> -			} else
> -				pr_warning("omap_device: %s.%d: activate "
> -					   "latency %d higher than exptected. "
> -					   "(%llu > %d)\n",
> -					   od->pdev.name, od->pdev.id,
> -					   od->pm_lat_level, act_lat,
> -					   odpl->activate_lat);
> +				if (strcmp(od->hwmods[0]->class->name, "uart"))
> +					pr_warning("omap_device: %s.%d: new worst case "
> +						"activate latency %d: %llu\n",
> +						od->pdev.name, od->pdev.id,
> +						od->pm_lat_level, act_lat);
> +			} else {
> +				if (strcmp(od->hwmods[0]->class->name, "uart"))
> +					pr_warning("omap_device: %s.%d: activate "
> +						"latency %d higher than exptected. "
> +						"(%llu > %d)\n",
> +						od->pdev.name, od->pdev.id,
> +						od->pm_lat_level, act_lat,
> +						odpl->activate_lat);

->activate_func() has already been called here, clocks are already on.

> @@ -183,7 +189,8 @@ static int _omap_device_deactivate(struct
> omap_device *od, u8 ignore_lat)
>  {
>  	struct timespec a, b, c;
> 
> -	pr_debug("omap_device: %s: deactivating\n", od->pdev.name);
> +	if (strcmp(od->hwmods[0]->class->name, "uart"))
> +		pr_debug("omap_device: %s: deactivating\n", od->pdev.name);

clocks are still on here.

> @@ -206,25 +213,29 @@ static int _omap_device_deactivate(struct
> omap_device *od, u8 ignore_lat)
>  		c = timespec_sub(b, a);
>  		deact_lat = timespec_to_ns(&c);
> 
> -		pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed time "
> -			 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> -			 deact_lat);
> +		if (strcmp(od->hwmods[0]->class->name, "uart"))
> +			pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed time "
> +				 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> +				 deact_lat);

I'll leave this to Kevin to decide what to do, but clocks are off
here...

>  		if (deact_lat > odpl->deactivate_lat) {
>  			odpl->deactivate_lat_worst = deact_lat;
>  			if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
>  				odpl->deactivate_lat = deact_lat;
> -				pr_warning("omap_device: %s.%d: new worst case "
> -					   "deactivate latency %d: %llu\n",
> -					   od->pdev.name, od->pdev.id,
> -					   od->pm_lat_level, deact_lat);
> -			} else
> -				pr_warning("omap_device: %s.%d: deactivate "
> +				if (strcmp(od->hwmods[0]->class->name, "uart"))
> +					pr_warning("omap_device: %s.%d: new worst case "
> +						   "deactivate latency %d: %llu\n",
> +						   od->pdev.name, od->pdev.id,
> +						   od->pm_lat_level, deact_lat);
> +			} else {
> +				if (strcmp(od->hwmods[0]->class->name, "uart"))
> +					pr_warning("omap_device: %s.%d: deactivate "
>  					   "latency %d higher than exptected. "
>  					   "(%llu > %d)\n",
>  					   od->pdev.name, od->pdev.id,
>  					   od->pm_lat_level, deact_lat,
>  					   odpl->deactivate_lat);
> +			}

and here...

-- 
balbi

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

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Raja, Govindraj]

[-- Attachment #1.1: Type: text/plain, Size: 11681 bytes --]

On Mon, Aug 1, 2011 at 2:33 PM, Felipe Balbi <balbi@ti.com> wrote:

> Hi,
>
> On Fri, Jul 29, 2011 at 08:43:49PM +0530, Govindraj wrote:
>
> [giant snip]
>
> > Actually there is much more than this:
> >
> > <<SNIP>>
> >
> > diff --git a/arch/arm/mach-omap2/clock.c b/arch/arm/mach-omap2/clock.c
> > index 180299e..221ffb9 100644
> > --- a/arch/arm/mach-omap2/clock.c
> > +++ b/arch/arm/mach-omap2/clock.c
> > @@ -12,7 +12,8 @@
> >   * it under the terms of the GNU General Public License version 2 as
> >   * published by the Free Software Foundation.
> >   */
> > -#undef DEBUG
> > +//#undef DEBUG
> > +#define DEBUG
>
> trailing... but you know that :-p
>

yes true.


> > @@ -254,14 +255,14 @@ void omap2_clk_disable(struct clk *clk)
> >               return;
> >       }
> >
> > -     pr_debug("clock: %s: decrementing usecount\n", clk->name);
> > +//   pr_debug("clock: %s: decrementing usecount\n", clk->name);
> >
> >       clk->usecount--;
> >
> >       if (clk->usecount > 0)
> >               return;
> >
> > -     pr_debug("clock: %s: disabling in hardware\n", clk->name);
> > +//   pr_debug("clock: %s: disabling in hardware\n", clk->name);
> >
> >       if (clk->ops && clk->ops->disable) {
> >               trace_clock_disable(clk->name, 0, smp_processor_id());
>
> this hunk is unnecessary. Clocks are always on when they are called.
>

The problem is:

[1]:

runtime_put -> *power.lock* - > rpm->suspend -> above pr_debug ->
console_write -> get_sync

-> *power.lock* -> rpm resume

power.lock contention.



>
> > @@ -290,14 +291,14 @@ int omap2_clk_enable(struct clk *clk)
> >  {
> >       int ret;
> >
> > -     pr_debug("clock: %s: incrementing usecount\n", clk->name);
> > +//   pr_debug("clock: %s: incrementing usecount\n", clk->name);
> >
> >       clk->usecount++;
> >
> >       if (clk->usecount > 1)
> >               return 0;
> >
> > -     pr_debug("clock: %s: enabling in hardware\n", clk->name);
> > +//   pr_debug("clock: %s: enabling in hardware\n", clk->name);
>
> these two is ok.
>
> > diff --git a/arch/arm/mach-omap2/omap_hwmod.c
> b/arch/arm/mach-omap2/omap_hwmod.c
> > index 7ed0479..8ca7d40 100644
> > --- a/arch/arm/mach-omap2/omap_hwmod.c
> > +++ b/arch/arm/mach-omap2/omap_hwmod.c
> > @@ -124,7 +124,8 @@
> >   * XXX error return values should be checked to ensure that they are
> >   * appropriate
> >   */
> > -#undef DEBUG
> > +//#undef DEBUG
> > +#define DEBUG
>
> trailing.
>
> > @@ -597,7 +598,8 @@ static int _enable_clocks(struct omap_hwmod *oh)
> >  {
> >       int i;
> >
> > -     pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
>
> instead of doing checks, you could move the print to the end of the
> function, when clocks are already enabled. When doind that, of course,
> update the comment to say "%s: clocks enabled\n".
>


the problem is the prints causing power.lock contention same as
the scenario in [1] above.



>
> > @@ -627,7 +629,8 @@ static int _disable_clocks(struct omap_hwmod *oh)
> >  {
> >       int i;
> >
> > -     pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
>
> check not needed, clocks are still on.
>

scenario [1]



>
> >
> >       if (oh->_clk)
> >               clk_disable(oh->_clk);
> > @@ -1232,7 +1235,8 @@ static int _enable(struct omap_hwmod *oh)
> >               return -EINVAL;
> >       }
> >
> > -     pr_debug("omap_hwmod: %s: enabling\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: enabling\n", oh->name);
>
> move it further down.
>
> > @@ -1264,8 +1268,9 @@ static int _enable(struct omap_hwmod *oh)
> >               }
> >       } else {
> >               _disable_clocks(oh);
> > -             pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
> > -                      oh->name, r);
> > +             if (strcmp(oh->class->name, "uart"))
> > +                     pr_debug("omap_hwmod: %s: _wait_target_ready:
> %d\n",
> > +                              oh->name, r);
>
> instead of adding check, move the print before _disable_clocks(oh).
>
> > @@ -1287,7 +1292,8 @@ static int _idle(struct omap_hwmod *oh)
> >               return -EINVAL;
> >       }
> >
> > -     pr_debug("omap_hwmod: %s: idling\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: idling\n", oh->name);
>
> I believe clocks are still on here too, no checks needed.
>
> > diff --git a/arch/arm/plat-omap/omap_device.c
> b/arch/arm/plat-omap/omap_device.c
> > index 49fc0df..7b27704 100644
> > --- a/arch/arm/plat-omap/omap_device.c
> > +++ b/arch/arm/plat-omap/omap_device.c
> > @@ -75,7 +75,8 @@
> >   * (device must be reinitialized at this point to use it again)
> >   *
> >   */
> > -#undef DEBUG
> > +//#undef DEBUG
> > +#define DEBUG
>
> trailing.
>
> > @@ -114,7 +115,8 @@ static int _omap_device_activate(struct
> > omap_device *od, u8 ignore_lat)
> >  {
> >       struct timespec a, b, c;
> >
> > -     pr_debug("omap_device: %s: activating\n", od->pdev.name);
> > +     if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +             pr_debug("omap_device: %s: activating\n", od->pdev.name);
>
> move it to the end of the function.
>
> > @@ -138,25 +140,29 @@ static int _omap_device_activate(struct
> > omap_device *od, u8 ignore_lat)
> >               c = timespec_sub(b, a);
> >               act_lat = timespec_to_ns(&c);
> >
> > -             pr_debug("omap_device: %s: pm_lat %d: activate: elapsed
> time "
> > -                      "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> > -                      act_lat);
> > +             if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +                     pr_debug("omap_device: %s: pm_lat %d: activate:
> elapsed time "
> > +                              "%llu nsec\n", od->pdev.name,
> od->pm_lat_level,
> > +                              act_lat);
>
> move it further down.
>
> >
> >               if (act_lat > odpl->activate_lat) {
> >                       odpl->activate_lat_worst = act_lat;
> >                       if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST)
> {
> >                               odpl->activate_lat = act_lat;
> > -                             pr_warning("omap_device: %s.%d: new worst
> case "
> > -                                        "activate latency %d: %llu\n",
> > -                                        od->pdev.name, od->pdev.id,
> > -                                        od->pm_lat_level, act_lat);
> > -                     } else
> > -                             pr_warning("omap_device: %s.%d: activate "
> > -                                        "latency %d higher than
> exptected. "
> > -                                        "(%llu > %d)\n",
> > -                                        od->pdev.name, od->pdev.id,
> > -                                        od->pm_lat_level, act_lat,
> > -                                        odpl->activate_lat);
> > +                             if (strcmp(od->hwmods[0]->class->name,
> "uart"))
> > +                                     pr_warning("omap_device: %s.%d: new
> worst case "
> > +                                             "activate latency %d:
> %llu\n",
> > +                                             od->pdev.name, od->pdev.id
> ,
> > +                                             od->pm_lat_level, act_lat);
> > +                     } else {
> > +                             if (strcmp(od->hwmods[0]->class->name,
> "uart"))
> > +                                     pr_warning("omap_device: %s.%d:
> activate "
> > +                                             "latency %d higher than
> exptected. "
> > +                                             "(%llu > %d)\n",
> > +                                             od->pdev.name, od->pdev.id
> ,
> > +                                             od->pm_lat_level, act_lat,
> > +                                             odpl->activate_lat);
>
> ->activate_func() has already been called here, clocks are already on.
>
> > @@ -183,7 +189,8 @@ static int _omap_device_deactivate(struct
> > omap_device *od, u8 ignore_lat)
> >  {
> >       struct timespec a, b, c;
> >
> > -     pr_debug("omap_device: %s: deactivating\n", od->pdev.name);
> > +     if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +             pr_debug("omap_device: %s: deactivating\n", od->pdev.name
> );
>
> clocks are still on here.
>
> > @@ -206,25 +213,29 @@ static int _omap_device_deactivate(struct
> > omap_device *od, u8 ignore_lat)
> >               c = timespec_sub(b, a);
> >               deact_lat = timespec_to_ns(&c);
> >
> > -             pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed
> time "
> > -                      "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> > -                      deact_lat);
> > +             if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +                     pr_debug("omap_device: %s: pm_lat %d: deactivate:
> elapsed time "
> > +                              "%llu nsec\n", od->pdev.name,
> od->pm_lat_level,
> > +                              deact_lat);
>
> I'll leave this to Kevin to decide what to do, but clocks are off
> here...
>

Yes fine.

Since most of these prints will be printed if DEBUG macro
is defined in respective files and *debug* is used in command line.

Can't leave uart clocks active always on debug cases.
[If *debug*  used as command line]
and gate uart clocks only for non debug cases.

With this approach at least we can have a clean solution
in uart driver also without adding clock gating from idle path.

Not sure if this agreeable.

As of now gating from idle path seems to be only clean approach.

-- 
Thanks,
Govindraj.R



> >               if (deact_lat > odpl->deactivate_lat) {
> >                       odpl->deactivate_lat_worst = deact_lat;
> >                       if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST)
> {
> >                               odpl->deactivate_lat = deact_lat;
> > -                             pr_warning("omap_device: %s.%d: new worst
> case "
> > -                                        "deactivate latency %d: %llu\n",
> > -                                        od->pdev.name, od->pdev.id,
> > -                                        od->pm_lat_level, deact_lat);
> > -                     } else
> > -                             pr_warning("omap_device: %s.%d: deactivate
> "
> > +                             if (strcmp(od->hwmods[0]->class->name,
> "uart"))
> > +                                     pr_warning("omap_device: %s.%d: new
> worst case "
> > +                                                "deactivate latency %d:
> %llu\n",
> > +                                                od->pdev.name, od->
> pdev.id,
> > +                                                od->pm_lat_level,
> deact_lat);
> > +                     } else {
> > +                             if (strcmp(od->hwmods[0]->class->name,
> "uart"))
> > +                                     pr_warning("omap_device: %s.%d:
> deactivate "
> >                                          "latency %d higher than
> exptected. "
> >                                          "(%llu > %d)\n",
> >                                          od->pdev.name, od->pdev.id,
> >                                          od->pm_lat_level, deact_lat,
> >                                          odpl->deactivate_lat);
> > +                     }
>
> and here...
>
> --
> balbi
>

[-- Attachment #1.2: Type: text/html, Size: 16868 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

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

Hi,

(fix your mailer dude)

On Mon, Aug 01, 2011 at 03:26:52PM +0530, Raja, Govindraj wrote:
>      > @@ -254,14 +255,14 @@ void omap2_clk_disable(struct clk *clk)
>      > � � � � � � � return;
>      > � � � }
>      >
>      > - � � pr_debug("clock: %s: decrementing usecount\n", clk->name);
>      > +// � pr_debug("clock: %s: decrementing usecount\n", clk->name);
>      >
>      > � � � clk->usecount--;
>      >
>      > � � � if (clk->usecount > 0)
>      > � � � � � � � return;
>      >
>      > - � � pr_debug("clock: %s: disabling in hardware\n", clk->name);
>      > +// � pr_debug("clock: %s: disabling in hardware\n", clk->name);
>      >
>      > � � � if (clk->ops && clk->ops->disable) {
>      > � � � � � � � trace_clock_disable(clk->name, 0, smp_processor_id());
> 
>      this hunk is unnecessary. Clocks are always on when they are called.
> 
>    The problem is:
>    [1]:
>    runtime_put -> *power.lock* - > rpm->suspend -> above pr_debug ->
>    console_write -> get_sync
>    -> *power.lock* -> rpm resume
>    power.lock contention.

Are you sure ? If the device is still on, won't that get_sync() only
increase the pm counter ? Instead of going through everything ?? Oh
well, this is becoming quite racy :-(

>      > @@ -290,14 +291,14 @@ int omap2_clk_enable(struct clk *clk)
>      > �{
>      > � � � int ret;
>      >
>      > - � � pr_debug("clock: %s: incrementing usecount\n", clk->name);
>      > +// � pr_debug("clock: %s: incrementing usecount\n", clk->name);
>      >
>      > � � � clk->usecount++;
>      >
>      > � � � if (clk->usecount > 1)
>      > � � � � � � � return 0;
>      >
>      > - � � pr_debug("clock: %s: enabling in hardware\n", clk->name);
>      > +// � pr_debug("clock: %s: enabling in hardware\n", clk->name);
> 
>      these two is ok.
>      > diff --git a/arch/arm/mach-omap2/omap_hwmod.c
>      b/arch/arm/mach-omap2/omap_hwmod.c
>      > index 7ed0479..8ca7d40 100644
>      > --- a/arch/arm/mach-omap2/omap_hwmod.c
>      > +++ b/arch/arm/mach-omap2/omap_hwmod.c
>      > @@ -124,7 +124,8 @@
>      > � * XXX error return values should be checked to ensure that they are
>      > � * appropriate
>      > � */
>      > -#undef DEBUG
>      > +//#undef DEBUG
>      > +#define DEBUG
> 
>      trailing.
>      > @@ -597,7 +598,8 @@ static int _enable_clocks(struct omap_hwmod *oh)
>      > �{
>      > � � � int i;
>      >
>      > - � � pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
>      > + � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
> 
>      instead of doing checks, you could move the print to the end of the
>      function, when clocks are already enabled. When doind that, of course,
>      update the comment to say "%s: clocks enabled\n".
> 
>    the problem is the prints causing power.lock contention same as�
>    the�scenario�in [1] above.
>    �
> 
>      > @@ -627,7 +629,8 @@ static int _disable_clocks(struct omap_hwmod *oh)
>      > �{
>      > � � � int i;
>      >
>      > - � � pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
>      > + � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_hwmod: %s: disabling clocks\n",
>      oh->name);
> 
>      check not needed, clocks are still on.
> 
>    scenario�[1]
>    �
> 
>      >
>      > � � � if (oh->_clk)
>      > � � � � � � � clk_disable(oh->_clk);
>      > @@ -1232,7 +1235,8 @@ static int _enable(struct omap_hwmod *oh)
>      > � � � � � � � return -EINVAL;
>      > � � � }
>      >
>      > - � � pr_debug("omap_hwmod: %s: enabling\n", oh->name);
>      > + � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_hwmod: %s: enabling\n", oh->name);
> 
>      move it further down.
>      > @@ -1264,8 +1268,9 @@ static int _enable(struct omap_hwmod *oh)
>      > � � � � � � � }
>      > � � � } else {
>      > � � � � � � � _disable_clocks(oh);
>      > - � � � � � � pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
>      > - � � � � � � � � � � �oh->name, r);
>      > + � � � � � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � � � � � pr_debug("omap_hwmod: %s: _wait_target_ready:
>      %d\n",
>      > + � � � � � � � � � � � � � � �oh->name, r);
> 
>      instead of adding check, move the print before _disable_clocks(oh).
>      > @@ -1287,7 +1292,8 @@ static int _idle(struct omap_hwmod *oh)
>      > � � � � � � � return -EINVAL;
>      > � � � }
>      >
>      > - � � pr_debug("omap_hwmod: %s: idling\n", oh->name);
>      > + � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_hwmod: %s: idling\n", oh->name);
> 
>      I believe clocks are still on here too, no checks needed.
>      > diff --git a/arch/arm/plat-omap/omap_device.c
>      b/arch/arm/plat-omap/omap_device.c
>      > index 49fc0df..7b27704 100644
>      > --- a/arch/arm/plat-omap/omap_device.c
>      > +++ b/arch/arm/plat-omap/omap_device.c
>      > @@ -75,7 +75,8 @@
>      > � * (device must be reinitialized at this point to use it again)
>      > � *
>      > � */
>      > -#undef DEBUG
>      > +//#undef DEBUG
>      > +#define DEBUG
> 
>      trailing.
>      > @@ -114,7 +115,8 @@ static int _omap_device_activate(struct
>      > omap_device *od, u8 ignore_lat)
>      > �{
>      > � � � struct timespec a, b, c;
>      >
>      > - � � pr_debug("omap_device: %s: activating\n", od->[2]pdev.name);
>      > + � � if (strcmp(od->hwmods[0]->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_device: %s: activating\n",
>      od->[3]pdev.name);
> 
>      move it to the end of the function.
>      > @@ -138,25 +140,29 @@ static int _omap_device_activate(struct
>      > omap_device *od, u8 ignore_lat)
>      > � � � � � � � c = timespec_sub(b, a);
>      > � � � � � � � act_lat = timespec_to_ns(&c);
>      >
>      > - � � � � � � pr_debug("omap_device: %s: pm_lat %d: activate: elapsed
>      time "
>      > - � � � � � � � � � � �"%llu nsec\n", od->[4]pdev.name,
>      od->pm_lat_level,
>      > - � � � � � � � � � � �act_lat);
>      > + � � � � � � if (strcmp(od->hwmods[0]->class->name, "uart"))
>      > + � � � � � � � � � � pr_debug("omap_device: %s: pm_lat %d: activate:
>      elapsed time "
>      > + � � � � � � � � � � � � � � �"%llu nsec\n", od->[5]pdev.name,
>      od->pm_lat_level,
>      > + � � � � � � � � � � � � � � �act_lat);
> 
>      move it further down.
>      >
>      > � � � � � � � if (act_lat > odpl->activate_lat) {
>      > � � � � � � � � � � � odpl->activate_lat_worst = act_lat;
>      > � � � � � � � � � � � if (odpl->flags &
>      OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
>      > � � � � � � � � � � � � � � � odpl->activate_lat = act_lat;
>      > - � � � � � � � � � � � � � � pr_warning("omap_device: %s.%d: new
>      worst case "
>      > - � � � � � � � � � � � � � � � � � � � �"activate latency %d:
>      %llu\n",
>      > - � � � � � � � � � � � � � � � � � � � �od->[6]pdev.name,
>      od->[7]pdev.id,
>      > - � � � � � � � � � � � � � � � � � � � �od->pm_lat_level, act_lat);
>      > - � � � � � � � � � � } else
>      > - � � � � � � � � � � � � � � pr_warning("omap_device: %s.%d: activate
>      "
>      > - � � � � � � � � � � � � � � � � � � � �"latency %d higher than
>      exptected. "
>      > - � � � � � � � � � � � � � � � � � � � �"(%llu > %d)\n",
>      > - � � � � � � � � � � � � � � � � � � � �od->[8]pdev.name,
>      od->[9]pdev.id,
>      > - � � � � � � � � � � � � � � � � � � � �od->pm_lat_level, act_lat,
>      > - � � � � � � � � � � � � � � � � � � � �odpl->activate_lat);
>      > + � � � � � � � � � � � � � � if (strcmp(od->hwmods[0]->class->name,
>      "uart"))
>      > + � � � � � � � � � � � � � � � � � � pr_warning("omap_device: %s.%d:
>      new worst case "
>      > + � � � � � � � � � � � � � � � � � � � � � � "activate latency %d:
>      %llu\n",
>      > + � � � � � � � � � � � � � � � � � � � � � � od->[10]pdev.name,
>      od->[11]pdev.id,
>      > + � � � � � � � � � � � � � � � � � � � � � � od->pm_lat_level,
>      act_lat);
>      > + � � � � � � � � � � } else {
>      > + � � � � � � � � � � � � � � if (strcmp(od->hwmods[0]->class->name,
>      "uart"))
>      > + � � � � � � � � � � � � � � � � � � pr_warning("omap_device: %s.%d:
>      activate "
>      > + � � � � � � � � � � � � � � � � � � � � � � "latency %d higher than
>      exptected. "
>      > + � � � � � � � � � � � � � � � � � � � � � � "(%llu > %d)\n",
>      > + � � � � � � � � � � � � � � � � � � � � � � od->[12]pdev.name,
>      od->[13]pdev.id,
>      > + � � � � � � � � � � � � � � � � � � � � � � od->pm_lat_level,
>      act_lat,
>      > + � � � � � � � � � � � � � � � � � � � � � � odpl->activate_lat);
> 
>      ->activate_func() has already been called here, clocks are already on.
>      > @@ -183,7 +189,8 @@ static int _omap_device_deactivate(struct
>      > omap_device *od, u8 ignore_lat)
>      > �{
>      > � � � struct timespec a, b, c;
>      >
>      > - � � pr_debug("omap_device: %s: deactivating\n", od->[14]pdev.name);
>      > + � � if (strcmp(od->hwmods[0]->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_device: %s: deactivating\n",
>      od->[15]pdev.name);
> 
>      clocks are still on here.
>      > @@ -206,25 +213,29 @@ static int _omap_device_deactivate(struct
>      > omap_device *od, u8 ignore_lat)
>      > � � � � � � � c = timespec_sub(b, a);
>      > � � � � � � � deact_lat = timespec_to_ns(&c);
>      >
>      > - � � � � � � pr_debug("omap_device: %s: pm_lat %d: deactivate:
>      elapsed time "
>      > - � � � � � � � � � � �"%llu nsec\n", od->[16]pdev.name,
>      od->pm_lat_level,
>      > - � � � � � � � � � � �deact_lat);
>      > + � � � � � � if (strcmp(od->hwmods[0]->class->name, "uart"))
>      > + � � � � � � � � � � pr_debug("omap_device: %s: pm_lat %d:
>      deactivate: elapsed time "
>      > + � � � � � � � � � � � � � � �"%llu nsec\n", od->[17]pdev.name,
>      od->pm_lat_level,
>      > + � � � � � � � � � � � � � � �deact_lat);
> 
>      I'll leave this to Kevin to decide what to do, but clocks are off
>      here...
> 
>    Yes fine.�
>    Since most of these prints will be printed if DEBUG macro
>    is defined in respective files and *debug* is used in command line.
>    Can't leave uart clocks active always on debug cases.
>    [If *debug* �used as command line]
>    and gate uart clocks only for non debug cases.
>    With this approach�at least�we can have a clean solution
>    in uart driver also without adding clock gating from idle path.
>    Not sure if this�agreeable.
>    As of now gating from idle path seems to be only clean approach.

I see.. that could be one way... let's see how Kevin feels about it
though.

-- 
balbi

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

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Mon, Aug 1, 2011 at 3:32 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>
> (fix your mailer dude)

Sorry some settings got screwed up with my mailer

>
> On Mon, Aug 01, 2011 at 03:26:52PM +0530, Raja, Govindraj wrote:

[..]

>>      this hunk is unnecessary. Clocks are always on when they are called.
>>
>>    The problem is:
>>    [1]:
>>    runtime_put -> *power.lock* - > rpm->suspend -> above pr_debug ->
>>    console_write -> get_sync
>>    -> *power.lock* -> rpm resume
>>    power.lock contention.
>
> Are you sure ? If the device is still on, won't that get_sync() only
> increase the pm counter ? Instead of going through everything ?? Oh
> well, this is becoming quite racy :-(

Yes true, but before it increments the counter it will take
power.lock

if we look into internals.

pm_runtime_get_sync -> *__pm_runtime_resume* --> rpm_resume

int __pm_runtime_resume(struct device *dev, int rpmflags)
{
 [..]
        spin_lock_irqsave(&dev->power.lock, flags);
        retval = rpm_resume(dev, rpmflags);
        spin_unlock_irqrestore(&dev->power.lock, flags);
[..]
}

Same applicable for runtime_put

[..]
>>      I'll leave this to Kevin to decide what to do, but clocks are off
>>      here...
>>
>>    Yes fine.�
>>    Since most of these prints will be printed if DEBUG macro
>>    is defined in respective files and *debug* is used in command line.
>>    Can't leave uart clocks active always on debug cases.
>>    [If *debug* �used as command line]
>>    and gate uart clocks only for non debug cases.
>>    With this approach�at least�we can have a clean solution
>>    in uart driver also without adding clock gating from idle path.
>>    Not sure if this�agreeable.
>>    As of now gating from idle path seems to be only clean approach.
>
> I see.. that could be one way... let's see how Kevin feels about it
> though.
>

OK.

--
Thanks,
Govindraj.R
_______________________________________________
linux-pm mailing list
linux-pm@lists.linux-foundation.org
https://lists.linux-foundation.org/mailman/listinfo/linux-pm

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Mon, Aug 1, 2011 at 3:32 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>
> (fix your mailer dude)

Sorry some settings got screwed up with my mailer

>
> On Mon, Aug 01, 2011 at 03:26:52PM +0530, Raja, Govindraj wrote:

[..]

>>      this hunk is unnecessary. Clocks are always on when they are called.
>>
>>    The problem is:
>>    [1]:
>>    runtime_put -> *power.lock* - > rpm->suspend -> above pr_debug ->
>>    console_write -> get_sync
>>    -> *power.lock* -> rpm resume
>>    power.lock contention.
>
> Are you sure ? If the device is still on, won't that get_sync() only
> increase the pm counter ? Instead of going through everything ?? Oh
> well, this is becoming quite racy :-(

Yes true, but before it increments the counter it will take
power.lock

if we look into internals.

pm_runtime_get_sync -> *__pm_runtime_resume* --> rpm_resume

int __pm_runtime_resume(struct device *dev, int rpmflags)
{
 [..]
        spin_lock_irqsave(&dev->power.lock, flags);
        retval = rpm_resume(dev, rpmflags);
        spin_unlock_irqrestore(&dev->power.lock, flags);
[..]
}

Same applicable for runtime_put

[..]
>>      I'll leave this to Kevin to decide what to do, but clocks are off
>>      here...
>>
>>    Yes fine.�
>>    Since most of these prints will be printed if DEBUG macro
>>    is defined in respective files and *debug* is used in command line.
>>    Can't leave uart clocks active always on debug cases.
>>    [If *debug* �used as command line]
>>    and gate uart clocks only for non debug cases.
>>    With this approach�at least�we can have a clean solution
>>    in uart driver also without adding clock gating from idle path.
>>    Not sure if this�agreeable.
>>    As of now gating from idle path seems to be only clean approach.
>
> I see.. that could be one way... let's see how Kevin feels about it
> though.
>

OK.

--
Thanks,
Govindraj.R
--
To unsubscribe from this list: send the line "unsubscribe linux-serial" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

[-- Attachment #1.1: Type: text/plain, Size: 12891 bytes --]

Hi,

(fix your mailer dude)

On Mon, Aug 01, 2011 at 03:26:52PM +0530, Raja, Govindraj wrote:
>      > @@ -254,14 +255,14 @@ void omap2_clk_disable(struct clk *clk)
>      > � � � � � � � return;
>      > � � � }
>      >
>      > - � � pr_debug("clock: %s: decrementing usecount\n", clk->name);
>      > +// � pr_debug("clock: %s: decrementing usecount\n", clk->name);
>      >
>      > � � � clk->usecount--;
>      >
>      > � � � if (clk->usecount > 0)
>      > � � � � � � � return;
>      >
>      > - � � pr_debug("clock: %s: disabling in hardware\n", clk->name);
>      > +// � pr_debug("clock: %s: disabling in hardware\n", clk->name);
>      >
>      > � � � if (clk->ops && clk->ops->disable) {
>      > � � � � � � � trace_clock_disable(clk->name, 0, smp_processor_id());
> 
>      this hunk is unnecessary. Clocks are always on when they are called.
> 
>    The problem is:
>    [1]:
>    runtime_put -> *power.lock* - > rpm->suspend -> above pr_debug ->
>    console_write -> get_sync
>    -> *power.lock* -> rpm resume
>    power.lock contention.

Are you sure ? If the device is still on, won't that get_sync() only
increase the pm counter ? Instead of going through everything ?? Oh
well, this is becoming quite racy :-(

>      > @@ -290,14 +291,14 @@ int omap2_clk_enable(struct clk *clk)
>      > �{
>      > � � � int ret;
>      >
>      > - � � pr_debug("clock: %s: incrementing usecount\n", clk->name);
>      > +// � pr_debug("clock: %s: incrementing usecount\n", clk->name);
>      >
>      > � � � clk->usecount++;
>      >
>      > � � � if (clk->usecount > 1)
>      > � � � � � � � return 0;
>      >
>      > - � � pr_debug("clock: %s: enabling in hardware\n", clk->name);
>      > +// � pr_debug("clock: %s: enabling in hardware\n", clk->name);
> 
>      these two is ok.
>      > diff --git a/arch/arm/mach-omap2/omap_hwmod.c
>      b/arch/arm/mach-omap2/omap_hwmod.c
>      > index 7ed0479..8ca7d40 100644
>      > --- a/arch/arm/mach-omap2/omap_hwmod.c
>      > +++ b/arch/arm/mach-omap2/omap_hwmod.c
>      > @@ -124,7 +124,8 @@
>      > � * XXX error return values should be checked to ensure that they are
>      > � * appropriate
>      > � */
>      > -#undef DEBUG
>      > +//#undef DEBUG
>      > +#define DEBUG
> 
>      trailing.
>      > @@ -597,7 +598,8 @@ static int _enable_clocks(struct omap_hwmod *oh)
>      > �{
>      > � � � int i;
>      >
>      > - � � pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
>      > + � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
> 
>      instead of doing checks, you could move the print to the end of the
>      function, when clocks are already enabled. When doind that, of course,
>      update the comment to say "%s: clocks enabled\n".
> 
>    the problem is the prints causing power.lock contention same as�
>    the�scenario�in [1] above.
>    �
> 
>      > @@ -627,7 +629,8 @@ static int _disable_clocks(struct omap_hwmod *oh)
>      > �{
>      > � � � int i;
>      >
>      > - � � pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
>      > + � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_hwmod: %s: disabling clocks\n",
>      oh->name);
> 
>      check not needed, clocks are still on.
> 
>    scenario�[1]
>    �
> 
>      >
>      > � � � if (oh->_clk)
>      > � � � � � � � clk_disable(oh->_clk);
>      > @@ -1232,7 +1235,8 @@ static int _enable(struct omap_hwmod *oh)
>      > � � � � � � � return -EINVAL;
>      > � � � }
>      >
>      > - � � pr_debug("omap_hwmod: %s: enabling\n", oh->name);
>      > + � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_hwmod: %s: enabling\n", oh->name);
> 
>      move it further down.
>      > @@ -1264,8 +1268,9 @@ static int _enable(struct omap_hwmod *oh)
>      > � � � � � � � }
>      > � � � } else {
>      > � � � � � � � _disable_clocks(oh);
>      > - � � � � � � pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
>      > - � � � � � � � � � � �oh->name, r);
>      > + � � � � � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � � � � � pr_debug("omap_hwmod: %s: _wait_target_ready:
>      %d\n",
>      > + � � � � � � � � � � � � � � �oh->name, r);
> 
>      instead of adding check, move the print before _disable_clocks(oh).
>      > @@ -1287,7 +1292,8 @@ static int _idle(struct omap_hwmod *oh)
>      > � � � � � � � return -EINVAL;
>      > � � � }
>      >
>      > - � � pr_debug("omap_hwmod: %s: idling\n", oh->name);
>      > + � � if (strcmp(oh->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_hwmod: %s: idling\n", oh->name);
> 
>      I believe clocks are still on here too, no checks needed.
>      > diff --git a/arch/arm/plat-omap/omap_device.c
>      b/arch/arm/plat-omap/omap_device.c
>      > index 49fc0df..7b27704 100644
>      > --- a/arch/arm/plat-omap/omap_device.c
>      > +++ b/arch/arm/plat-omap/omap_device.c
>      > @@ -75,7 +75,8 @@
>      > � * (device must be reinitialized at this point to use it again)
>      > � *
>      > � */
>      > -#undef DEBUG
>      > +//#undef DEBUG
>      > +#define DEBUG
> 
>      trailing.
>      > @@ -114,7 +115,8 @@ static int _omap_device_activate(struct
>      > omap_device *od, u8 ignore_lat)
>      > �{
>      > � � � struct timespec a, b, c;
>      >
>      > - � � pr_debug("omap_device: %s: activating\n", od->[2]pdev.name);
>      > + � � if (strcmp(od->hwmods[0]->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_device: %s: activating\n",
>      od->[3]pdev.name);
> 
>      move it to the end of the function.
>      > @@ -138,25 +140,29 @@ static int _omap_device_activate(struct
>      > omap_device *od, u8 ignore_lat)
>      > � � � � � � � c = timespec_sub(b, a);
>      > � � � � � � � act_lat = timespec_to_ns(&c);
>      >
>      > - � � � � � � pr_debug("omap_device: %s: pm_lat %d: activate: elapsed
>      time "
>      > - � � � � � � � � � � �"%llu nsec\n", od->[4]pdev.name,
>      od->pm_lat_level,
>      > - � � � � � � � � � � �act_lat);
>      > + � � � � � � if (strcmp(od->hwmods[0]->class->name, "uart"))
>      > + � � � � � � � � � � pr_debug("omap_device: %s: pm_lat %d: activate:
>      elapsed time "
>      > + � � � � � � � � � � � � � � �"%llu nsec\n", od->[5]pdev.name,
>      od->pm_lat_level,
>      > + � � � � � � � � � � � � � � �act_lat);
> 
>      move it further down.
>      >
>      > � � � � � � � if (act_lat > odpl->activate_lat) {
>      > � � � � � � � � � � � odpl->activate_lat_worst = act_lat;
>      > � � � � � � � � � � � if (odpl->flags &
>      OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
>      > � � � � � � � � � � � � � � � odpl->activate_lat = act_lat;
>      > - � � � � � � � � � � � � � � pr_warning("omap_device: %s.%d: new
>      worst case "
>      > - � � � � � � � � � � � � � � � � � � � �"activate latency %d:
>      %llu\n",
>      > - � � � � � � � � � � � � � � � � � � � �od->[6]pdev.name,
>      od->[7]pdev.id,
>      > - � � � � � � � � � � � � � � � � � � � �od->pm_lat_level, act_lat);
>      > - � � � � � � � � � � } else
>      > - � � � � � � � � � � � � � � pr_warning("omap_device: %s.%d: activate
>      "
>      > - � � � � � � � � � � � � � � � � � � � �"latency %d higher than
>      exptected. "
>      > - � � � � � � � � � � � � � � � � � � � �"(%llu > %d)\n",
>      > - � � � � � � � � � � � � � � � � � � � �od->[8]pdev.name,
>      od->[9]pdev.id,
>      > - � � � � � � � � � � � � � � � � � � � �od->pm_lat_level, act_lat,
>      > - � � � � � � � � � � � � � � � � � � � �odpl->activate_lat);
>      > + � � � � � � � � � � � � � � if (strcmp(od->hwmods[0]->class->name,
>      "uart"))
>      > + � � � � � � � � � � � � � � � � � � pr_warning("omap_device: %s.%d:
>      new worst case "
>      > + � � � � � � � � � � � � � � � � � � � � � � "activate latency %d:
>      %llu\n",
>      > + � � � � � � � � � � � � � � � � � � � � � � od->[10]pdev.name,
>      od->[11]pdev.id,
>      > + � � � � � � � � � � � � � � � � � � � � � � od->pm_lat_level,
>      act_lat);
>      > + � � � � � � � � � � } else {
>      > + � � � � � � � � � � � � � � if (strcmp(od->hwmods[0]->class->name,
>      "uart"))
>      > + � � � � � � � � � � � � � � � � � � pr_warning("omap_device: %s.%d:
>      activate "
>      > + � � � � � � � � � � � � � � � � � � � � � � "latency %d higher than
>      exptected. "
>      > + � � � � � � � � � � � � � � � � � � � � � � "(%llu > %d)\n",
>      > + � � � � � � � � � � � � � � � � � � � � � � od->[12]pdev.name,
>      od->[13]pdev.id,
>      > + � � � � � � � � � � � � � � � � � � � � � � od->pm_lat_level,
>      act_lat,
>      > + � � � � � � � � � � � � � � � � � � � � � � odpl->activate_lat);
> 
>      ->activate_func() has already been called here, clocks are already on.
>      > @@ -183,7 +189,8 @@ static int _omap_device_deactivate(struct
>      > omap_device *od, u8 ignore_lat)
>      > �{
>      > � � � struct timespec a, b, c;
>      >
>      > - � � pr_debug("omap_device: %s: deactivating\n", od->[14]pdev.name);
>      > + � � if (strcmp(od->hwmods[0]->class->name, "uart"))
>      > + � � � � � � pr_debug("omap_device: %s: deactivating\n",
>      od->[15]pdev.name);
> 
>      clocks are still on here.
>      > @@ -206,25 +213,29 @@ static int _omap_device_deactivate(struct
>      > omap_device *od, u8 ignore_lat)
>      > � � � � � � � c = timespec_sub(b, a);
>      > � � � � � � � deact_lat = timespec_to_ns(&c);
>      >
>      > - � � � � � � pr_debug("omap_device: %s: pm_lat %d: deactivate:
>      elapsed time "
>      > - � � � � � � � � � � �"%llu nsec\n", od->[16]pdev.name,
>      od->pm_lat_level,
>      > - � � � � � � � � � � �deact_lat);
>      > + � � � � � � if (strcmp(od->hwmods[0]->class->name, "uart"))
>      > + � � � � � � � � � � pr_debug("omap_device: %s: pm_lat %d:
>      deactivate: elapsed time "
>      > + � � � � � � � � � � � � � � �"%llu nsec\n", od->[17]pdev.name,
>      od->pm_lat_level,
>      > + � � � � � � � � � � � � � � �deact_lat);
> 
>      I'll leave this to Kevin to decide what to do, but clocks are off
>      here...
> 
>    Yes fine.�
>    Since most of these prints will be printed if DEBUG macro
>    is defined in respective files and *debug* is used in command line.
>    Can't leave uart clocks active always on debug cases.
>    [If *debug* �used as command line]
>    and gate uart clocks only for non debug cases.
>    With this approach�at least�we can have a clean solution
>    in uart driver also without adding clock gating from idle path.
>    Not sure if this�agreeable.
>    As of now gating from idle path seems to be only clean approach.

I see.. that could be one way... let's see how Kevin feels about it
though.

-- 
balbi

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

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

> Hi,
>
> On Fri, Jul 29, 2011 at 08:43:49PM +0530, Govindraj wrote:
>
> [giant snip]
>
> > Actually there is much more than this:
> >
> > <<SNIP>>
> >
> > diff --git a/arch/arm/mach-omap2/clock.c b/arch/arm/mach-omap2/clock.c
> > index 180299e..221ffb9 100644
> > --- a/arch/arm/mach-omap2/clock.c
> > +++ b/arch/arm/mach-omap2/clock.c
> > @@ -12,7 +12,8 @@
> >   * it under the terms of the GNU General Public License version 2 as
> >   * published by the Free Software Foundation.
> >   */
> > -#undef DEBUG
> > +//#undef DEBUG
> > +#define DEBUG
>
> trailing... but you know that :-p
>

yes true.


> > @@ -254,14 +255,14 @@ void omap2_clk_disable(struct clk *clk)
> >               return;
> >       }
> >
> > -     pr_debug("clock: %s: decrementing usecount\n", clk->name);
> > +//   pr_debug("clock: %s: decrementing usecount\n", clk->name);
> >
> >       clk->usecount--;
> >
> >       if (clk->usecount > 0)
> >               return;
> >
> > -     pr_debug("clock: %s: disabling in hardware\n", clk->name);
> > +//   pr_debug("clock: %s: disabling in hardware\n", clk->name);
> >
> >       if (clk->ops && clk->ops->disable) {
> >               trace_clock_disable(clk->name, 0, smp_processor_id());
>
> this hunk is unnecessary. Clocks are always on when they are called.
>

The problem is:

[1]:

runtime_put -> *power.lock* - > rpm->suspend -> above pr_debug ->
console_write -> get_sync

-> *power.lock* -> rpm resume

power.lock contention.



>
> > @@ -290,14 +291,14 @@ int omap2_clk_enable(struct clk *clk)
> >  {
> >       int ret;
> >
> > -     pr_debug("clock: %s: incrementing usecount\n", clk->name);
> > +//   pr_debug("clock: %s: incrementing usecount\n", clk->name);
> >
> >       clk->usecount++;
> >
> >       if (clk->usecount > 1)
> >               return 0;
> >
> > -     pr_debug("clock: %s: enabling in hardware\n", clk->name);
> > +//   pr_debug("clock: %s: enabling in hardware\n", clk->name);
>
> these two is ok.
>
> > diff --git a/arch/arm/mach-omap2/omap_hwmod.c
> b/arch/arm/mach-omap2/omap_hwmod.c
> > index 7ed0479..8ca7d40 100644
> > --- a/arch/arm/mach-omap2/omap_hwmod.c
> > +++ b/arch/arm/mach-omap2/omap_hwmod.c
> > @@ -124,7 +124,8 @@
> >   * XXX error return values should be checked to ensure that they are
> >   * appropriate
> >   */
> > -#undef DEBUG
> > +//#undef DEBUG
> > +#define DEBUG
>
> trailing.
>
> > @@ -597,7 +598,8 @@ static int _enable_clocks(struct omap_hwmod *oh)
> >  {
> >       int i;
> >
> > -     pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
>
> instead of doing checks, you could move the print to the end of the
> function, when clocks are already enabled. When doind that, of course,
> update the comment to say "%s: clocks enabled\n".
>


the problem is the prints causing power.lock contention same as
the scenario in [1] above.



>
> > @@ -627,7 +629,8 @@ static int _disable_clocks(struct omap_hwmod *oh)
> >  {
> >       int i;
> >
> > -     pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
>
> check not needed, clocks are still on.
>

scenario [1]



>
> >
> >       if (oh->_clk)
> >               clk_disable(oh->_clk);
> > @@ -1232,7 +1235,8 @@ static int _enable(struct omap_hwmod *oh)
> >               return -EINVAL;
> >       }
> >
> > -     pr_debug("omap_hwmod: %s: enabling\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: enabling\n", oh->name);
>
> move it further down.
>
> > @@ -1264,8 +1268,9 @@ static int _enable(struct omap_hwmod *oh)
> >               }
> >       } else {
> >               _disable_clocks(oh);
> > -             pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
> > -                      oh->name, r);
> > +             if (strcmp(oh->class->name, "uart"))
> > +                     pr_debug("omap_hwmod: %s: _wait_target_ready:
> %d\n",
> > +                              oh->name, r);
>
> instead of adding check, move the print before _disable_clocks(oh).
>
> > @@ -1287,7 +1292,8 @@ static int _idle(struct omap_hwmod *oh)
> >               return -EINVAL;
> >       }
> >
> > -     pr_debug("omap_hwmod: %s: idling\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: idling\n", oh->name);
>
> I believe clocks are still on here too, no checks needed.
>
> > diff --git a/arch/arm/plat-omap/omap_device.c
> b/arch/arm/plat-omap/omap_device.c
> > index 49fc0df..7b27704 100644
> > --- a/arch/arm/plat-omap/omap_device.c
> > +++ b/arch/arm/plat-omap/omap_device.c
> > @@ -75,7 +75,8 @@
> >   * (device must be reinitialized at this point to use it again)
> >   *
> >   */
> > -#undef DEBUG
> > +//#undef DEBUG
> > +#define DEBUG
>
> trailing.
>
> > @@ -114,7 +115,8 @@ static int _omap_device_activate(struct
> > omap_device *od, u8 ignore_lat)
> >  {
> >       struct timespec a, b, c;
> >
> > -     pr_debug("omap_device: %s: activating\n", od->pdev.name);
> > +     if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +             pr_debug("omap_device: %s: activating\n", od->pdev.name);
>
> move it to the end of the function.
>
> > @@ -138,25 +140,29 @@ static int _omap_device_activate(struct
> > omap_device *od, u8 ignore_lat)
> >               c = timespec_sub(b, a);
> >               act_lat = timespec_to_ns(&c);
> >
> > -             pr_debug("omap_device: %s: pm_lat %d: activate: elapsed
> time "
> > -                      "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> > -                      act_lat);
> > +             if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +                     pr_debug("omap_device: %s: pm_lat %d: activate:
> elapsed time "
> > +                              "%llu nsec\n", od->pdev.name,
> od->pm_lat_level,
> > +                              act_lat);
>
> move it further down.
>
> >
> >               if (act_lat > odpl->activate_lat) {
> >                       odpl->activate_lat_worst = act_lat;
> >                       if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST)
> {
> >                               odpl->activate_lat = act_lat;
> > -                             pr_warning("omap_device: %s.%d: new worst
> case "
> > -                                        "activate latency %d: %llu\n",
> > -                                        od->pdev.name, od->pdev.id,
> > -                                        od->pm_lat_level, act_lat);
> > -                     } else
> > -                             pr_warning("omap_device: %s.%d: activate "
> > -                                        "latency %d higher than
> exptected. "
> > -                                        "(%llu > %d)\n",
> > -                                        od->pdev.name, od->pdev.id,
> > -                                        od->pm_lat_level, act_lat,
> > -                                        odpl->activate_lat);
> > +                             if (strcmp(od->hwmods[0]->class->name,
> "uart"))
> > +                                     pr_warning("omap_device: %s.%d: new
> worst case "
> > +                                             "activate latency %d:
> %llu\n",
> > +                                             od->pdev.name, od->pdev.id
> ,
> > +                                             od->pm_lat_level, act_lat);
> > +                     } else {
> > +                             if (strcmp(od->hwmods[0]->class->name,
> "uart"))
> > +                                     pr_warning("omap_device: %s.%d:
> activate "
> > +                                             "latency %d higher than
> exptected. "
> > +                                             "(%llu > %d)\n",
> > +                                             od->pdev.name, od->pdev.id
> ,
> > +                                             od->pm_lat_level, act_lat,
> > +                                             odpl->activate_lat);
>
> ->activate_func() has already been called here, clocks are already on.
>
> > @@ -183,7 +189,8 @@ static int _omap_device_deactivate(struct
> > omap_device *od, u8 ignore_lat)
> >  {
> >       struct timespec a, b, c;
> >
> > -     pr_debug("omap_device: %s: deactivating\n", od->pdev.name);
> > +     if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +             pr_debug("omap_device: %s: deactivating\n", od->pdev.name
> );
>
> clocks are still on here.
>
> > @@ -206,25 +213,29 @@ static int _omap_device_deactivate(struct
> > omap_device *od, u8 ignore_lat)
> >               c = timespec_sub(b, a);
> >               deact_lat = timespec_to_ns(&c);
> >
> > -             pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed
> time "
> > -                      "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> > -                      deact_lat);
> > +             if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +                     pr_debug("omap_device: %s: pm_lat %d: deactivate:
> elapsed time "
> > +                              "%llu nsec\n", od->pdev.name,
> od->pm_lat_level,
> > +                              deact_lat);
>
> I'll leave this to Kevin to decide what to do, but clocks are off
> here...
>

Yes fine.

Since most of these prints will be printed if DEBUG macro
is defined in respective files and *debug* is used in command line.

Can't leave uart clocks active always on debug cases.
[If *debug*  used as command line]
and gate uart clocks only for non debug cases.

With this approach at least we can have a clean solution
in uart driver also without adding clock gating from idle path.

Not sure if this agreeable.

As of now gating from idle path seems to be only clean approach.

-- 
Thanks,
Govindraj.R

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

> Hi,
>
> On Fri, Jul 29, 2011 at 08:43:49PM +0530, Govindraj wrote:
>
> [giant snip]
>
> > Actually there is much more than this:
> >
> > <<SNIP>>
> >
> > diff --git a/arch/arm/mach-omap2/clock.c b/arch/arm/mach-omap2/clock.c
> > index 180299e..221ffb9 100644
> > --- a/arch/arm/mach-omap2/clock.c
> > +++ b/arch/arm/mach-omap2/clock.c
> > @@ -12,7 +12,8 @@
> >   * it under the terms of the GNU General Public License version 2 as
> >   * published by the Free Software Foundation.
> >   */
> > -#undef DEBUG
> > +//#undef DEBUG
> > +#define DEBUG
>
> trailing... but you know that :-p
>

yes true.


> > @@ -254,14 +255,14 @@ void omap2_clk_disable(struct clk *clk)
> >               return;
> >       }
> >
> > -     pr_debug("clock: %s: decrementing usecount\n", clk->name);
> > +//   pr_debug("clock: %s: decrementing usecount\n", clk->name);
> >
> >       clk->usecount--;
> >
> >       if (clk->usecount > 0)
> >               return;
> >
> > -     pr_debug("clock: %s: disabling in hardware\n", clk->name);
> > +//   pr_debug("clock: %s: disabling in hardware\n", clk->name);
> >
> >       if (clk->ops && clk->ops->disable) {
> >               trace_clock_disable(clk->name, 0, smp_processor_id());
>
> this hunk is unnecessary. Clocks are always on when they are called.
>

The problem is:

[1]:

runtime_put -> *power.lock* - > rpm->suspend -> above pr_debug ->
console_write -> get_sync

-> *power.lock* -> rpm resume

power.lock contention.



>
> > @@ -290,14 +291,14 @@ int omap2_clk_enable(struct clk *clk)
> >  {
> >       int ret;
> >
> > -     pr_debug("clock: %s: incrementing usecount\n", clk->name);
> > +//   pr_debug("clock: %s: incrementing usecount\n", clk->name);
> >
> >       clk->usecount++;
> >
> >       if (clk->usecount > 1)
> >               return 0;
> >
> > -     pr_debug("clock: %s: enabling in hardware\n", clk->name);
> > +//   pr_debug("clock: %s: enabling in hardware\n", clk->name);
>
> these two is ok.
>
> > diff --git a/arch/arm/mach-omap2/omap_hwmod.c
> b/arch/arm/mach-omap2/omap_hwmod.c
> > index 7ed0479..8ca7d40 100644
> > --- a/arch/arm/mach-omap2/omap_hwmod.c
> > +++ b/arch/arm/mach-omap2/omap_hwmod.c
> > @@ -124,7 +124,8 @@
> >   * XXX error return values should be checked to ensure that they are
> >   * appropriate
> >   */
> > -#undef DEBUG
> > +//#undef DEBUG
> > +#define DEBUG
>
> trailing.
>
> > @@ -597,7 +598,8 @@ static int _enable_clocks(struct omap_hwmod *oh)
> >  {
> >       int i;
> >
> > -     pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
>
> instead of doing checks, you could move the print to the end of the
> function, when clocks are already enabled. When doind that, of course,
> update the comment to say "%s: clocks enabled\n".
>


the problem is the prints causing power.lock contention same as
the scenario in [1] above.



>
> > @@ -627,7 +629,8 @@ static int _disable_clocks(struct omap_hwmod *oh)
> >  {
> >       int i;
> >
> > -     pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
>
> check not needed, clocks are still on.
>

scenario [1]



>
> >
> >       if (oh->_clk)
> >               clk_disable(oh->_clk);
> > @@ -1232,7 +1235,8 @@ static int _enable(struct omap_hwmod *oh)
> >               return -EINVAL;
> >       }
> >
> > -     pr_debug("omap_hwmod: %s: enabling\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: enabling\n", oh->name);
>
> move it further down.
>
> > @@ -1264,8 +1268,9 @@ static int _enable(struct omap_hwmod *oh)
> >               }
> >       } else {
> >               _disable_clocks(oh);
> > -             pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
> > -                      oh->name, r);
> > +             if (strcmp(oh->class->name, "uart"))
> > +                     pr_debug("omap_hwmod: %s: _wait_target_ready:
> %d\n",
> > +                              oh->name, r);
>
> instead of adding check, move the print before _disable_clocks(oh).
>
> > @@ -1287,7 +1292,8 @@ static int _idle(struct omap_hwmod *oh)
> >               return -EINVAL;
> >       }
> >
> > -     pr_debug("omap_hwmod: %s: idling\n", oh->name);
> > +     if (strcmp(oh->class->name, "uart"))
> > +             pr_debug("omap_hwmod: %s: idling\n", oh->name);
>
> I believe clocks are still on here too, no checks needed.
>
> > diff --git a/arch/arm/plat-omap/omap_device.c
> b/arch/arm/plat-omap/omap_device.c
> > index 49fc0df..7b27704 100644
> > --- a/arch/arm/plat-omap/omap_device.c
> > +++ b/arch/arm/plat-omap/omap_device.c
> > @@ -75,7 +75,8 @@
> >   * (device must be reinitialized at this point to use it again)
> >   *
> >   */
> > -#undef DEBUG
> > +//#undef DEBUG
> > +#define DEBUG
>
> trailing.
>
> > @@ -114,7 +115,8 @@ static int _omap_device_activate(struct
> > omap_device *od, u8 ignore_lat)
> >  {
> >       struct timespec a, b, c;
> >
> > -     pr_debug("omap_device: %s: activating\n", od->pdev.name);
> > +     if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +             pr_debug("omap_device: %s: activating\n", od->pdev.name);
>
> move it to the end of the function.
>
> > @@ -138,25 +140,29 @@ static int _omap_device_activate(struct
> > omap_device *od, u8 ignore_lat)
> >               c = timespec_sub(b, a);
> >               act_lat = timespec_to_ns(&c);
> >
> > -             pr_debug("omap_device: %s: pm_lat %d: activate: elapsed
> time "
> > -                      "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> > -                      act_lat);
> > +             if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +                     pr_debug("omap_device: %s: pm_lat %d: activate:
> elapsed time "
> > +                              "%llu nsec\n", od->pdev.name,
> od->pm_lat_level,
> > +                              act_lat);
>
> move it further down.
>
> >
> >               if (act_lat > odpl->activate_lat) {
> >                       odpl->activate_lat_worst = act_lat;
> >                       if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST)
> {
> >                               odpl->activate_lat = act_lat;
> > -                             pr_warning("omap_device: %s.%d: new worst
> case "
> > -                                        "activate latency %d: %llu\n",
> > -                                        od->pdev.name, od->pdev.id,
> > -                                        od->pm_lat_level, act_lat);
> > -                     } else
> > -                             pr_warning("omap_device: %s.%d: activate "
> > -                                        "latency %d higher than
> exptected. "
> > -                                        "(%llu > %d)\n",
> > -                                        od->pdev.name, od->pdev.id,
> > -                                        od->pm_lat_level, act_lat,
> > -                                        odpl->activate_lat);
> > +                             if (strcmp(od->hwmods[0]->class->name,
> "uart"))
> > +                                     pr_warning("omap_device: %s.%d: new
> worst case "
> > +                                             "activate latency %d:
> %llu\n",
> > +                                             od->pdev.name, od->pdev.id
> ,
> > +                                             od->pm_lat_level, act_lat);
> > +                     } else {
> > +                             if (strcmp(od->hwmods[0]->class->name,
> "uart"))
> > +                                     pr_warning("omap_device: %s.%d:
> activate "
> > +                                             "latency %d higher than
> exptected. "
> > +                                             "(%llu > %d)\n",
> > +                                             od->pdev.name, od->pdev.id
> ,
> > +                                             od->pm_lat_level, act_lat,
> > +                                             odpl->activate_lat);
>
> ->activate_func() has already been called here, clocks are already on.
>
> > @@ -183,7 +189,8 @@ static int _omap_device_deactivate(struct
> > omap_device *od, u8 ignore_lat)
> >  {
> >       struct timespec a, b, c;
> >
> > -     pr_debug("omap_device: %s: deactivating\n", od->pdev.name);
> > +     if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +             pr_debug("omap_device: %s: deactivating\n", od->pdev.name
> );
>
> clocks are still on here.
>
> > @@ -206,25 +213,29 @@ static int _omap_device_deactivate(struct
> > omap_device *od, u8 ignore_lat)
> >               c = timespec_sub(b, a);
> >               deact_lat = timespec_to_ns(&c);
> >
> > -             pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed
> time "
> > -                      "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> > -                      deact_lat);
> > +             if (strcmp(od->hwmods[0]->class->name, "uart"))
> > +                     pr_debug("omap_device: %s: pm_lat %d: deactivate:
> elapsed time "
> > +                              "%llu nsec\n", od->pdev.name,
> od->pm_lat_level,
> > +                              deact_lat);
>
> I'll leave this to Kevin to decide what to do, but clocks are off
> here...
>

Yes fine.

Since most of these prints will be printed if DEBUG macro
is defined in respective files and *debug* is used in command line.

Can't leave uart clocks active always on debug cases.
[If *debug*  used as command line]
and gate uart clocks only for non debug cases.

With this approach at least we can have a clean solution
in uart driver also without adding clock gating from idle path.

Not sure if this agreeable.

As of now gating from idle path seems to be only clean approach.

-- 
Thanks,
Govindraj.R

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj]

On Fri, Jul 29, 2011 at 7:32 PM, Felipe Balbi <balbi@ti.com> wrote:
> Hi,
>
> On Fri, Jul 29, 2011 at 06:28:32PM +0530, Govindraj wrote:
>> On Fri, Jul 29, 2011 at 5:49 PM, Felipe Balbi <balbi@ti.com> wrote:
>> > On Fri, Jul 29, 2011 at 05:29:12PM +0530, Govindraj wrote:
>> >> Yes fine, But there are scenarios even before first runtime_suspend happens,
>> >>
>> >> ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
>> >> (omap_device_enable in this case) debug printk -> console_write -> get_sync.
>> >>
>> >> there are numerous such scenarios where we end from runtime context
>> >> to runtime api context again, or jumping from one uart port operation
>> >> to uart print operation.
>> >
>> > calling pm_runtime_get_sync() should not be a problem. It should only
>> > increase the usage counters... This sounds like a race condition on the
>> > driver, no ?
>>
>> Actually when we call a API to enable clocks we except the internals of API
>> to just enable clocks and return.
>>
>> *Clock enable API should not cause or trigger to do a _device_driver_operation_
>> even before enabling clocks of the device-driver which called it*
>>
>> for uart context get_sync can land me to uart driver back
>> even before enabling the uart clocks due to printks.
>
> only if _you_ have prints or _your_ runtime_*() calls, no ?
>
> Let's say omap_hwmod.c wants to do a print:
>
> -> printk()
>  -> pm_runtime_get_sync
>    -> console_write
>  -> pm_runtim_put
>
> now, if you have a printk() on your runtime_resume() before you enable
> the clocks, then I can see why you would deadlock:
>
> -> pm_runtime_get_sync
>  -> omap_serial_runtime_resume
>    -> printk
>      -> pm_runtime_get_sync
>        -> omap_serial_runtime_resume
>          -> printk
>           -> pm_runtime_get_sync
>            .....
>
> maybe I'm missing something, but can you add a stack dump on your
> ->runtime_resume and ->runtime_suspend methods, just so we try to figure
> out who's to blame here ?
>
>> > What you're experiencing, if I understood correctly, is a deadlock ? In
>> > that case, can you try to track the locking mechanism on the omap-serial
>> > driver to try to find if there isn't anything obviously wrong ?
>> >
>>
>> Yes deadlocks. due to entering from runtime context to runtime context
>> or entering from uart_port_operation to uart_console_write ops.
>>
>> There are already port locks used extensively within the uart driver
>> to secure a port operation.
>>
>> But cannot secure a port operation while using clock_enable API.
>> since clock enable API can land the control back to uart_console_write
>> operation..
>
> but in that case, if clock isn't enabled, why don't you just ignore the
> print and enable the clock ?? Just return 0 and continue with
> clk_enable() ??
>
>> >> So either we should not have those prints from pm_generic layers or suppress
>> >> them(seems pretty much a problem for a clean design within the driver
>> >> using console_lock/unlock for every get_sync, and for
>> >> runtime_put we cannot suppress the prints as it gets scheduled later)
>> >>
>> >> or if other folks who really need those prints form pm_generic* layers
>> >> to debug and analysis then we have no other choice rather control
>> >> the clk_enable/disable from outside driver code in idle path.
>> >
>> > yeah, none of these would be nice :-(
>> >
>> > I think this needs more debugging to be sure what's exactly going on.
>> > What's exactly causing the deadlock ? Which lock is held and never
>> > released ?
>> >
>>
>> I had done some investigations, from scenarios it simply boils down to fact
>> to handle clock within uart driver, uart driver expects clock enable API* used
>> to just enable uart clocks but rather not trigger a _uart_ops_ within which
>> kind of unacceptable from the uart_driver context.
>
> ok, now I see what you mean:
>
> 113 static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
> 114 {
> 115         struct timespec a, b, c;
> 116
> 117         pr_debug("omap_device: %s: activating\n", od->pdev.name);
> 118
> 119         while (od->pm_lat_level > 0) {
> 120                 struct omap_device_pm_latency *odpl;
> 121                 unsigned long long act_lat = 0;
> 122
> 123                 od->pm_lat_level--;
> 124
> 125                 odpl = od->pm_lats + od->pm_lat_level;
> 126
> 127                 if (!ignore_lat &&
> 128                     (od->dev_wakeup_lat <= od->_dev_wakeup_lat_limit))
> 129                         break;
> 130
> 131                 read_persistent_clock(&a);
> 132
> 133                 /* XXX check return code */
> 134                 odpl->activate_func(od);
> 135
> 136                 read_persistent_clock(&b);
> 137
> 138                 c = timespec_sub(b, a);
> 139                 act_lat = timespec_to_ns(&c);
> 140
> 141                 pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
> 142                          "%llu nsec\n", od->pdev.name, od->pm_lat_level,
> 143                          act_lat);
> 144
> 145                 if (act_lat > odpl->activate_lat) {
> 146                         odpl->activate_lat_worst = act_lat;
> 147                         if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
> 148                                 odpl->activate_lat = act_lat;
> 149                                 pr_warning("omap_device: %s.%d: new worst case "
> 150                                            "activate latency %d: %llu\n",
> 151                                            od->pdev.name, od->pdev.id,
> 152                                            od->pm_lat_level, act_lat);
> 153                         } else
> 154                                 pr_warning("omap_device: %s.%d: activate "
> 155                                            "latency %d higher than exptected. "
> 156                                            "(%llu > %d)\n",
> 157                                            od->pdev.name, od->pdev.id,
> 158                                            od->pm_lat_level, act_lat,
> 159                                            odpl->activate_lat);
> 160                 }
> 161
> 162                 od->dev_wakeup_lat -= odpl->activate_lat;
> 163         }
> 164
> 165         return 0;
> 166 }
>
> When that first pr_debug() triggers, UART's hwmod could be disabled, and
> that would trigger the state I described above where you would keep on
> calling pm_runtime_get_sync() forever ;-)
>
> isn't it enough to patch it like below:
>
> diff --git a/arch/arm/plat-omap/omap_device.c b/arch/arm/plat-omap/omap_device.c
> index b6b4097..560f622 100644
> --- a/arch/arm/plat-omap/omap_device.c
> +++ b/arch/arm/plat-omap/omap_device.c
> @@ -114,8 +114,6 @@ static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
>  {
>        struct timespec a, b, c;
>
> -       pr_debug("omap_device: %s: activating\n", od->pdev.name);
> -
>        while (od->pm_lat_level > 0) {
>                struct omap_device_pm_latency *odpl;
>                unsigned long long act_lat = 0;
> @@ -162,6 +160,8 @@ static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
>                od->dev_wakeup_lat -= odpl->activate_lat;
>        }
>
> +       pr_debug("omap_device: %s: activated\n", od->pdev.name);
> +
>        return 0;
>  }
>

Actually there is much more than this:

<<SNIP>>

diff --git a/arch/arm/mach-omap2/clock.c b/arch/arm/mach-omap2/clock.c
index 180299e..221ffb9 100644
--- a/arch/arm/mach-omap2/clock.c
+++ b/arch/arm/mach-omap2/clock.c
@@ -12,7 +12,8 @@
  * it under the terms of the GNU General Public License version 2 as
  * published by the Free Software Foundation.
  */
-#undef DEBUG
+//#undef DEBUG
+#define DEBUG

 #include <linux/kernel.h>
 #include <linux/list.h>
@@ -254,14 +255,14 @@ void omap2_clk_disable(struct clk *clk)
 		return;
 	}

-	pr_debug("clock: %s: decrementing usecount\n", clk->name);
+//	pr_debug("clock: %s: decrementing usecount\n", clk->name);

 	clk->usecount--;

 	if (clk->usecount > 0)
 		return;

-	pr_debug("clock: %s: disabling in hardware\n", clk->name);
+//	pr_debug("clock: %s: disabling in hardware\n", clk->name);

 	if (clk->ops && clk->ops->disable) {
 		trace_clock_disable(clk->name, 0, smp_processor_id());
@@ -290,14 +291,14 @@ int omap2_clk_enable(struct clk *clk)
 {
 	int ret;

-	pr_debug("clock: %s: incrementing usecount\n", clk->name);
+//	pr_debug("clock: %s: incrementing usecount\n", clk->name);

 	clk->usecount++;

 	if (clk->usecount > 1)
 		return 0;

-	pr_debug("clock: %s: enabling in hardware\n", clk->name);
+//	pr_debug("clock: %s: enabling in hardware\n", clk->name);

 	if (clk->parent) {
 		ret = omap2_clk_enable(clk->parent);
diff --git a/arch/arm/mach-omap2/omap_hwmod.c b/arch/arm/mach-omap2/omap_hwmod.c
index 7ed0479..8ca7d40 100644
--- a/arch/arm/mach-omap2/omap_hwmod.c
+++ b/arch/arm/mach-omap2/omap_hwmod.c
@@ -124,7 +124,8 @@
  * XXX error return values should be checked to ensure that they are
  * appropriate
  */
-#undef DEBUG
+//#undef DEBUG
+#define DEBUG

 #include <linux/kernel.h>
 #include <linux/errno.h>
@@ -597,7 +598,8 @@ static int _enable_clocks(struct omap_hwmod *oh)
 {
 	int i;

-	pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);
+	if (strcmp(oh->class->name, "uart"))
+		pr_debug("omap_hwmod: %s: enabling clocks\n", oh->name);

 	if (oh->_clk)
 		clk_enable(oh->_clk);
@@ -627,7 +629,8 @@ static int _disable_clocks(struct omap_hwmod *oh)
 {
 	int i;

-	pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);
+	if (strcmp(oh->class->name, "uart"))
+		pr_debug("omap_hwmod: %s: disabling clocks\n", oh->name);

 	if (oh->_clk)
 		clk_disable(oh->_clk);
@@ -1232,7 +1235,8 @@ static int _enable(struct omap_hwmod *oh)
 		return -EINVAL;
 	}

-	pr_debug("omap_hwmod: %s: enabling\n", oh->name);
+	if (strcmp(oh->class->name, "uart"))
+		pr_debug("omap_hwmod: %s: enabling\n", oh->name);

 	/*
 	 * If an IP contains only one HW reset line, then de-assert it in order
@@ -1264,8 +1268,9 @@ static int _enable(struct omap_hwmod *oh)
 		}
 	} else {
 		_disable_clocks(oh);
-		pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
-			 oh->name, r);
+		if (strcmp(oh->class->name, "uart"))
+			pr_debug("omap_hwmod: %s: _wait_target_ready: %d\n",
+				 oh->name, r);
 	}

 	return r;
@@ -1287,7 +1292,8 @@ static int _idle(struct omap_hwmod *oh)
 		return -EINVAL;
 	}

-	pr_debug("omap_hwmod: %s: idling\n", oh->name);
+	if (strcmp(oh->class->name, "uart"))
+		pr_debug("omap_hwmod: %s: idling\n", oh->name);

 	if (oh->class->sysc)
 		_idle_sysc(oh);
diff --git a/arch/arm/plat-omap/omap_device.c b/arch/arm/plat-omap/omap_device.c
index 49fc0df..7b27704 100644
--- a/arch/arm/plat-omap/omap_device.c
+++ b/arch/arm/plat-omap/omap_device.c
@@ -75,7 +75,8 @@
  * (device must be reinitialized at this point to use it again)
  *
  */
-#undef DEBUG
+//#undef DEBUG
+#define DEBUG

 #include <linux/kernel.h>
 #include <linux/platform_device.h>
@@ -114,7 +115,8 @@ static int _omap_device_activate(struct
omap_device *od, u8 ignore_lat)
 {
 	struct timespec a, b, c;

-	pr_debug("omap_device: %s: activating\n", od->pdev.name);
+	if (strcmp(od->hwmods[0]->class->name, "uart"))
+		pr_debug("omap_device: %s: activating\n", od->pdev.name);

 	while (od->pm_lat_level > 0) {
 		struct omap_device_pm_latency *odpl;
@@ -138,25 +140,29 @@ static int _omap_device_activate(struct
omap_device *od, u8 ignore_lat)
 		c = timespec_sub(b, a);
 		act_lat = timespec_to_ns(&c);

-		pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
-			 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
-			 act_lat);
+		if (strcmp(od->hwmods[0]->class->name, "uart"))
+			pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
+				 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
+				 act_lat);

 		if (act_lat > odpl->activate_lat) {
 			odpl->activate_lat_worst = act_lat;
 			if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
 				odpl->activate_lat = act_lat;
-				pr_warning("omap_device: %s.%d: new worst case "
-					   "activate latency %d: %llu\n",
-					   od->pdev.name, od->pdev.id,
-					   od->pm_lat_level, act_lat);
-			} else
-				pr_warning("omap_device: %s.%d: activate "
-					   "latency %d higher than exptected. "
-					   "(%llu > %d)\n",
-					   od->pdev.name, od->pdev.id,
-					   od->pm_lat_level, act_lat,
-					   odpl->activate_lat);
+				if (strcmp(od->hwmods[0]->class->name, "uart"))
+					pr_warning("omap_device: %s.%d: new worst case "
+						"activate latency %d: %llu\n",
+						od->pdev.name, od->pdev.id,
+						od->pm_lat_level, act_lat);
+			} else {
+				if (strcmp(od->hwmods[0]->class->name, "uart"))
+					pr_warning("omap_device: %s.%d: activate "
+						"latency %d higher than exptected. "
+						"(%llu > %d)\n",
+						od->pdev.name, od->pdev.id,
+						od->pm_lat_level, act_lat,
+						odpl->activate_lat);
+			}
 		}

 		od->dev_wakeup_lat -= odpl->activate_lat;
@@ -183,7 +189,8 @@ static int _omap_device_deactivate(struct
omap_device *od, u8 ignore_lat)
 {
 	struct timespec a, b, c;

-	pr_debug("omap_device: %s: deactivating\n", od->pdev.name);
+	if (strcmp(od->hwmods[0]->class->name, "uart"))
+		pr_debug("omap_device: %s: deactivating\n", od->pdev.name);

 	while (od->pm_lat_level < od->pm_lats_cnt) {
 		struct omap_device_pm_latency *odpl;
@@ -206,25 +213,29 @@ static int _omap_device_deactivate(struct
omap_device *od, u8 ignore_lat)
 		c = timespec_sub(b, a);
 		deact_lat = timespec_to_ns(&c);

-		pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed time "
-			 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
-			 deact_lat);
+		if (strcmp(od->hwmods[0]->class->name, "uart"))
+			pr_debug("omap_device: %s: pm_lat %d: deactivate: elapsed time "
+				 "%llu nsec\n", od->pdev.name, od->pm_lat_level,
+				 deact_lat);

 		if (deact_lat > odpl->deactivate_lat) {
 			odpl->deactivate_lat_worst = deact_lat;
 			if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
 				odpl->deactivate_lat = deact_lat;
-				pr_warning("omap_device: %s.%d: new worst case "
-					   "deactivate latency %d: %llu\n",
-					   od->pdev.name, od->pdev.id,
-					   od->pm_lat_level, deact_lat);
-			} else
-				pr_warning("omap_device: %s.%d: deactivate "
+				if (strcmp(od->hwmods[0]->class->name, "uart"))
+					pr_warning("omap_device: %s.%d: new worst case "
+						   "deactivate latency %d: %llu\n",
+						   od->pdev.name, od->pdev.id,
+						   od->pm_lat_level, deact_lat);
+			} else {
+				if (strcmp(od->hwmods[0]->class->name, "uart"))
+					pr_warning("omap_device: %s.%d: deactivate "
 					   "latency %d higher than exptected. "
 					   "(%llu > %d)\n",
 					   od->pdev.name, od->pdev.id,
 					   od->pm_lat_level, deact_lat,
 					   odpl->deactivate_lat);
+			}
 		}


<<SNIP>>


>
> either the above or something like:
>
> if (pm_runtime_suspended(dev))
>        return 0;
>
> on console_write() ??

Consider the scenario where after bootup uart is idled
with runtime auto suspend so now state of console
uart is RPM_SUSPENDED.

Now you connect a pendrive to ehci-port.

Missing critical usb host <-> device_enumeration prints?

uart_console rpm_suspended state ->

usb_device mass storage device found print ->

console_write -> return without printing.

--
Thanks,
Govindraj.R

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

[-- Attachment #1.1: Type: text/plain, Size: 7283 bytes --]

Hi,

On Fri, Jul 29, 2011 at 06:28:32PM +0530, Govindraj wrote:
> On Fri, Jul 29, 2011 at 5:49 PM, Felipe Balbi <balbi@ti.com> wrote:
> > On Fri, Jul 29, 2011 at 05:29:12PM +0530, Govindraj wrote:
> >> Yes fine, But there are scenarios even before first runtime_suspend happens,
> >>
> >> ex: uart_port_configure -> get_sync -> pm_generic_runtime_resume
> >> (omap_device_enable in this case) debug printk -> console_write -> get_sync.
> >>
> >> there are numerous such scenarios where we end from runtime context
> >> to runtime api context again, or jumping from one uart port operation
> >> to uart print operation.
> >
> > calling pm_runtime_get_sync() should not be a problem. It should only
> > increase the usage counters... This sounds like a race condition on the
> > driver, no ?
> 
> Actually when we call a API to enable clocks we except the internals of API
> to just enable clocks and return.
> 
> *Clock enable API should not cause or trigger to do a _device_driver_operation_
> even before enabling clocks of the device-driver which called it*
> 
> for uart context get_sync can land me to uart driver back
> even before enabling the uart clocks due to printks.

only if _you_ have prints or _your_ runtime_*() calls, no ?

Let's say omap_hwmod.c wants to do a print:

-> printk()
  -> pm_runtime_get_sync
    -> console_write
  -> pm_runtim_put

now, if you have a printk() on your runtime_resume() before you enable
the clocks, then I can see why you would deadlock:

-> pm_runtime_get_sync
  -> omap_serial_runtime_resume
    -> printk
      -> pm_runtime_get_sync
        -> omap_serial_runtime_resume
	  -> printk
	   -> pm_runtime_get_sync
	    .....

maybe I'm missing something, but can you add a stack dump on your
->runtime_resume and ->runtime_suspend methods, just so we try to figure
out who's to blame here ?

> > What you're experiencing, if I understood correctly, is a deadlock ? In
> > that case, can you try to track the locking mechanism on the omap-serial
> > driver to try to find if there isn't anything obviously wrong ?
> >
> 
> Yes deadlocks. due to entering from runtime context to runtime context
> or entering from uart_port_operation to uart_console_write ops.
> 
> There are already port locks used extensively within the uart driver
> to secure a port operation.
> 
> But cannot secure a port operation while using clock_enable API.
> since clock enable API can land the control back to uart_console_write
> operation..

but in that case, if clock isn't enabled, why don't you just ignore the
print and enable the clock ?? Just return 0 and continue with
clk_enable() ??

> >> So either we should not have those prints from pm_generic layers or suppress
> >> them(seems pretty much a problem for a clean design within the driver
> >> using console_lock/unlock for every get_sync, and for
> >> runtime_put we cannot suppress the prints as it gets scheduled later)
> >>
> >> or if other folks who really need those prints form pm_generic* layers
> >> to debug and analysis then we have no other choice rather control
> >> the clk_enable/disable from outside driver code in idle path.
> >
> > yeah, none of these would be nice :-(
> >
> > I think this needs more debugging to be sure what's exactly going on.
> > What's exactly causing the deadlock ? Which lock is held and never
> > released ?
> >
> 
> I had done some investigations, from scenarios it simply boils down to fact
> to handle clock within uart driver, uart driver expects clock enable API* used
> to just enable uart clocks but rather not trigger a _uart_ops_ within which
> kind of unacceptable from the uart_driver context.

ok, now I see what you mean:

113 static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
114 {
115         struct timespec a, b, c;
116
117         pr_debug("omap_device: %s: activating\n", od->pdev.name);
118
119         while (od->pm_lat_level > 0) {
120                 struct omap_device_pm_latency *odpl;
121                 unsigned long long act_lat = 0;
122
123                 od->pm_lat_level--;
124
125                 odpl = od->pm_lats + od->pm_lat_level;
126
127                 if (!ignore_lat &&
128                     (od->dev_wakeup_lat <= od->_dev_wakeup_lat_limit))
129                         break;
130
131                 read_persistent_clock(&a);
132
133                 /* XXX check return code */
134                 odpl->activate_func(od);
135
136                 read_persistent_clock(&b);
137
138                 c = timespec_sub(b, a);
139                 act_lat = timespec_to_ns(&c);
140
141                 pr_debug("omap_device: %s: pm_lat %d: activate: elapsed time "
142                          "%llu nsec\n", od->pdev.name, od->pm_lat_level,
143                          act_lat);
144
145                 if (act_lat > odpl->activate_lat) {
146                         odpl->activate_lat_worst = act_lat;
147                         if (odpl->flags & OMAP_DEVICE_LATENCY_AUTO_ADJUST) {
148                                 odpl->activate_lat = act_lat;
149                                 pr_warning("omap_device: %s.%d: new worst case "
150                                            "activate latency %d: %llu\n",
151                                            od->pdev.name, od->pdev.id,
152                                            od->pm_lat_level, act_lat);
153                         } else
154                                 pr_warning("omap_device: %s.%d: activate "
155                                            "latency %d higher than exptected. "
156                                            "(%llu > %d)\n",
157                                            od->pdev.name, od->pdev.id,
158                                            od->pm_lat_level, act_lat,
159                                            odpl->activate_lat);
160                 }
161
162                 od->dev_wakeup_lat -= odpl->activate_lat;
163         }
164
165         return 0;
166 }

When that first pr_debug() triggers, UART's hwmod could be disabled, and
that would trigger the state I described above where you would keep on
calling pm_runtime_get_sync() forever ;-)

isn't it enough to patch it like below:

diff --git a/arch/arm/plat-omap/omap_device.c b/arch/arm/plat-omap/omap_device.c
index b6b4097..560f622 100644
--- a/arch/arm/plat-omap/omap_device.c
+++ b/arch/arm/plat-omap/omap_device.c
@@ -114,8 +114,6 @@ static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
 {
        struct timespec a, b, c;
 
-       pr_debug("omap_device: %s: activating\n", od->pdev.name);
-
        while (od->pm_lat_level > 0) {
                struct omap_device_pm_latency *odpl;
                unsigned long long act_lat = 0;
@@ -162,6 +160,8 @@ static int _omap_device_activate(struct omap_device *od, u8 ignore_lat)
                od->dev_wakeup_lat -= odpl->activate_lat;
        }
 
+       pr_debug("omap_device: %s: activated\n", od->pdev.name);
+
        return 0;
 }
 

either the above or something like:

if (pm_runtime_suspended(dev))
	return 0;

on console_write() ??

-- 
balbi

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

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [RFC v2]: Issues implementing clock handling mechanism within UART driver

[Felipe Balbi]

[-- Attachment #1.1: Type: text/plain, Size: 1304 bytes --]

Hi,

On Fri, Jul 29, 2011 at 04:54:44PM +0530, Govindraj wrote:
> On Fri, Jul 29, 2011 at 3:25 PM, Felipe Balbi <balbi@ti.com> wrote:
> > Hi,
> >
> 
> Thanks for replying.
> 
> > On Thu, Jul 28, 2011 at 02:59:55PM +0530, Govindraj.R wrote:
> >> Proposal:
> >> --------
> >>       1. For the UART, follow the current approach of locking the console in
> >>          Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
> >>          That is, continue using the prepare/resume Idle calls in idle path.
> >
> > I believe you should be using ->prepare() to prevent that any other
> > work on UART won't trigger a console_write() right now. Maybe only
> > queueing the work for after ->complete() or, maybe, just ignoring the
> > work and loosing some prints, dunno.
> >
> 
> Yes true, for suspend path but for Idle path we don't have any such
> mechanism.

aha... good point ;-)

> I have done clock gating in idle path integrating irq chaining patches.
> hosted in gitorious here[1].
> 
> Was consolidating whether this approach is OK,
> or
> Are there any other approaches that I should consider?

why don't you also start queueing writes after the first call to
runtime_suspend() and flush them after the first call runtime_resume()??

-- 
balbi

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

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

[RFC v2]: Issues implementing clock handling mechanism within UART driver

[Govindraj.R]

To handle uart clocks within uart driver we need the *semantics of clock enable
API should not internally trigger any UART PORT operation* even before
completing clock_enable.

Ex: while configuring baud rate we may use runtime api's to enable uart port.
get_sync -> printk -> call console uart to print

For example, say we are calling Uart_configure baud to configure the baud-rate.
Even before this operation completes, if there is print, we may switch to uart
write operation which is undesirable.

This occurs due to any printks called from omap_device ()/omap_hwmod ()/clk layers
which come in the flow from pm_runtime_get_sync/ pm_runtime_put_autosuspend API's.

	1. pm_runtime_get _sync -> printk -> console_write -> pm_runtime_get_sync
	2. pm_runtime_ put_autosuspend -> rpm_suspend -> pm_generic suspend ->
	   omap_device_disable -> debug prints -> console_write -> pm_runtime_get_sync

This leads to a deadlock caused by contention of the power_lock from
the same runtime API context.

Work-around explored:
--------------------
Use console lock aggressively around each get_sync/put_sync.

	Uart_configure baud {
		1. Console_lock
		2. pm_runtime_get_sync
		3. Console_unlock (and send the prints accumulated in the
		   log buffer to the console) which leads to a console_write .
		4. This console_write in turn leads to a console_lock+pm_runtime_get_sync
		5. Also  Console_unlock is undesirable here since it jumps to
		   console write even before baud config was complete.
	}

Locking the console around a pm_runtime_get_sync()will make sure that all prints
are sent to the log-buffer until the console in unlocked, thereby getting rid of
recursively jumping from one port op to another even before current port
operation is complete.

However, this leads to:
	1. Cant bind put_autosuspend with console lock as they get scheduled later
	   put -> print -> console_write -> get_sync (one runtime API context we
	   may enter another runtime API power lock contention)
	2. Using console_lock wrapper everywhere in driver to suppress prints
	   from get_sync is too aggressive in nature.
	3. During Boot-up, console_lock is not available until uart driver
	   completes its registration with kernel console_driver.

Observing the semantics of console_lock/unlock, it seems undesirable to be used
within uart driver. But can rather be used form global stand point to suppress
uart prints.

Example:
1. While system wide suspending
2. In cpu idle path., etc.

Proposal:
--------
	1. For the UART, follow the current approach of locking the console in
	   Idle/Suspend path before cutting the clock but using pm_runtime_putsync.
	   That is, continue using the prepare/resume Idle calls in idle path.
	2. Other Approach would be adding conditions to debug prints from
	   omap_device/ omap_hwmod/clock_framework avoid calling these debug
	   prints for uart.
	   Or Even a debug macro that would not debug prints if the context is
	   from uart.

Any further approaches are welcome.

Have captured little more details compared to v1 posted erlier:
http://www.mail-archive.com/linux-omap@vger.kernel.org/msg52707.html

-- 
1.7.4.1