* ehci dynamic debug problem
@ 2012-04-13 8:56 Johannes Stezenbach
2012-04-13 14:35 ` Alan Stern
0 siblings, 1 reply; 13+ messages in thread
From: Johannes Stezenbach @ 2012-04-13 8:56 UTC (permalink / raw)
To: Jason Baron; +Cc: linux-kernel, Alan Stern, linux-usb
Hi,
I have a quirky device and enabled dynamic debug to
see the ehci driver debug messages to help me diagnose
the problem. I see stuff like this:
[1790542.363321] ehci_hub_control:940: ehci_hcd 0000:00:1a.0: \xffffffd8\xffffff94\xffffff94\xffffffa8\xffffff81\xffffffff\xffffffff\xffffffff\xffffffff}[<\xffffff81\xffffffff\xffffffff\xffffffff\xffffffff\x01
[1790542.363470] ehci_hub_control:940: ehci_hcd 0000:00:1a.0: \xffffffd8\xffffff94\xffffff94\xffffffa8\xffffff81\xffffffff\xffffffff\xffffffff\xffffffff}[<\xffffff81\xffffffff\xffffffff\xffffffff\xffffffff\x01
The problem is in ehci-dbg.c:
#define dbg_port(ehci, label, port, status) { \
char _buf [80]; \
dbg_port_buf (_buf, sizeof _buf, label, port, status); \
ehci_dbg (ehci, "%s\n", _buf); \
}
dbg_port_buf() is a no op when DEBUG is not defined, thus
the ehci_dbg() prints uninitialized memory.
Does dynamic debug offer an "is the message two lines below enabled" test?
Simply changing the "#ifdef DEBUG" for dbg_port_buf()
to "#if defined(DEBUG) || defined(CONFIG_DYNAMIC_DEBUG)"
is probably not acceptable due to the overhead of dbg_port_buf()?
Thanks,
Johannes
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-13 8:56 ehci dynamic debug problem Johannes Stezenbach
@ 2012-04-13 14:35 ` Alan Stern
2012-04-13 14:57 ` Johannes Stezenbach
0 siblings, 1 reply; 13+ messages in thread
From: Alan Stern @ 2012-04-13 14:35 UTC (permalink / raw)
To: Johannes Stezenbach; +Cc: Jason Baron, linux-kernel, linux-usb
On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
> Hi,
>
> I have a quirky device and enabled dynamic debug to
> see the ehci driver debug messages to help me diagnose
> the problem. I see stuff like this:
>
> [1790542.363321] ehci_hub_control:940: ehci_hcd 0000:00:1a.0: \xffffffd8\xffffff94\xffffff94\xffffffa8\xffffff81\xffffffff\xffffffff\xffffffff\xffffffff}[<\xffffff81\xffffffff\xffffffff\xffffffff\xffffffff\x01
> [1790542.363470] ehci_hub_control:940: ehci_hcd 0000:00:1a.0: \xffffffd8\xffffff94\xffffff94\xffffffa8\xffffff81\xffffffff\xffffffff\xffffffff\xffffffff}[<\xffffff81\xffffffff\xffffffff\xffffffff\xffffffff\x01
>
> The problem is in ehci-dbg.c:
>
> #define dbg_port(ehci, label, port, status) { \
> char _buf [80]; \
> dbg_port_buf (_buf, sizeof _buf, label, port, status); \
> ehci_dbg (ehci, "%s\n", _buf); \
> }
>
> dbg_port_buf() is a no op when DEBUG is not defined, thus
> the ehci_dbg() prints uninitialized memory.
Interesting. I have never run across this, because I never use dynamic
debug.
> Does dynamic debug offer an "is the message two lines below enabled" test?
> Simply changing the "#ifdef DEBUG" for dbg_port_buf()
> to "#if defined(DEBUG) || defined(CONFIG_DYNAMIC_DEBUG)"
> is probably not acceptable due to the overhead of dbg_port_buf()?
I don't understand your question. Doesn't dbg_port_buf need to be
defined whenever dynamic debugging is enabled?
Alternatively, the definition of dbg_port_buf (and related routines) in
the !defined(DEBUG) case could be changed; you could add
buf[0] = 0;
That way you wouldn't get garbage out, although you wouldn't get
anything useful either.
Alan Stern
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-13 14:35 ` Alan Stern
@ 2012-04-13 14:57 ` Johannes Stezenbach
2012-04-13 15:19 ` Alan Stern
0 siblings, 1 reply; 13+ messages in thread
From: Johannes Stezenbach @ 2012-04-13 14:57 UTC (permalink / raw)
To: Alan Stern; +Cc: Jason Baron, linux-kernel, linux-usb
On Fri, Apr 13, 2012 at 10:35:59AM -0400, Alan Stern wrote:
> On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
> >
> > Does dynamic debug offer an "is the message two lines below enabled" test?
> > Simply changing the "#ifdef DEBUG" for dbg_port_buf()
> > to "#if defined(DEBUG) || defined(CONFIG_DYNAMIC_DEBUG)"
> > is probably not acceptable due to the overhead of dbg_port_buf()?
>
> I don't understand your question. Doesn't dbg_port_buf need to be
> defined whenever dynamic debugging is enabled?
>
> Alternatively, the definition of dbg_port_buf (and related routines) in
> the !defined(DEBUG) case could be changed; you could add
>
> buf[0] = 0;
>
> That way you wouldn't get garbage out, although you wouldn't get
> anything useful either.
The ideal solution I'm looking for gives useful output
when dynamic debugging is enabled for ehci, but does no
useless string formatting when CONFIG_DYNAMIC_DEBUG is y
but the dynamic debug for ehci is disabled.
Thanks,
Johannes
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-13 14:57 ` Johannes Stezenbach
@ 2012-04-13 15:19 ` Alan Stern
2012-04-13 17:41 ` Johannes Stezenbach
0 siblings, 1 reply; 13+ messages in thread
From: Alan Stern @ 2012-04-13 15:19 UTC (permalink / raw)
To: Johannes Stezenbach; +Cc: Jason Baron, linux-kernel, linux-usb
On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
> On Fri, Apr 13, 2012 at 10:35:59AM -0400, Alan Stern wrote:
> > On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
> > >
> > > Does dynamic debug offer an "is the message two lines below enabled" test?
> > > Simply changing the "#ifdef DEBUG" for dbg_port_buf()
> > > to "#if defined(DEBUG) || defined(CONFIG_DYNAMIC_DEBUG)"
> > > is probably not acceptable due to the overhead of dbg_port_buf()?
> >
> > I don't understand your question. Doesn't dbg_port_buf need to be
> > defined whenever dynamic debugging is enabled?
> >
> > Alternatively, the definition of dbg_port_buf (and related routines) in
> > the !defined(DEBUG) case could be changed; you could add
> >
> > buf[0] = 0;
> >
> > That way you wouldn't get garbage out, although you wouldn't get
> > anything useful either.
>
> The ideal solution I'm looking for gives useful output
> when dynamic debugging is enabled for ehci, but does no
> useless string formatting when CONFIG_DYNAMIC_DEBUG is y
> but the dynamic debug for ehci is disabled.
But there is no such thing as dynamic debug for ehci, is there?
There's a separate dynamic debug setting for each dev_dbg statement.
So your ideal solution makes no sense.
Alan Stern
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-13 15:19 ` Alan Stern
@ 2012-04-13 17:41 ` Johannes Stezenbach
2012-04-13 18:13 ` Alan Stern
0 siblings, 1 reply; 13+ messages in thread
From: Johannes Stezenbach @ 2012-04-13 17:41 UTC (permalink / raw)
To: Alan Stern; +Cc: Jason Baron, linux-kernel, linux-usb
On Fri, Apr 13, 2012 at 11:19:37AM -0400, Alan Stern wrote:
> On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
>
> > On Fri, Apr 13, 2012 at 10:35:59AM -0400, Alan Stern wrote:
> > > On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
> > > >
> > > > Does dynamic debug offer an "is the message two lines below enabled" test?
> > > > Simply changing the "#ifdef DEBUG" for dbg_port_buf()
> > > > to "#if defined(DEBUG) || defined(CONFIG_DYNAMIC_DEBUG)"
> > > > is probably not acceptable due to the overhead of dbg_port_buf()?
> > >
> > > I don't understand your question. Doesn't dbg_port_buf need to be
> > > defined whenever dynamic debugging is enabled?
> > >
> > > Alternatively, the definition of dbg_port_buf (and related routines) in
> > > the !defined(DEBUG) case could be changed; you could add
> > >
> > > buf[0] = 0;
> > >
> > > That way you wouldn't get garbage out, although you wouldn't get
> > > anything useful either.
> >
> > The ideal solution I'm looking for gives useful output
> > when dynamic debugging is enabled for ehci, but does no
> > useless string formatting when CONFIG_DYNAMIC_DEBUG is y
> > but the dynamic debug for ehci is disabled.
>
> But there is no such thing as dynamic debug for ehci, is there?
> There's a separate dynamic debug setting for each dev_dbg statement.
> So your ideal solution makes no sense.
When CONFIG_DYNAMIC_DEBUG=y but ehci debug is disabled
in /sys/kernel/debug/dynamic_debug/control, then
dbg_port() calls dbg_port_buf() which would
format the string, then calls ehci_dbg() which
calls dev_dbg() which discards it.
Does it make sense now?
Thanks,
Johannes
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-13 17:41 ` Johannes Stezenbach
@ 2012-04-13 18:13 ` Alan Stern
2012-04-13 19:03 ` Johannes Stezenbach
0 siblings, 1 reply; 13+ messages in thread
From: Alan Stern @ 2012-04-13 18:13 UTC (permalink / raw)
To: Johannes Stezenbach; +Cc: Jason Baron, linux-kernel, linux-usb
On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
> > But there is no such thing as dynamic debug for ehci, is there?
> > There's a separate dynamic debug setting for each dev_dbg statement.
> > So your ideal solution makes no sense.
>
> When CONFIG_DYNAMIC_DEBUG=y but ehci debug is disabled
There is no such thing as ehci debug! So how can it be disabled?
There's only an individual setting for each line of debugging code.
> in /sys/kernel/debug/dynamic_debug/control, then
> dbg_port() calls dbg_port_buf() which would
> format the string, then calls ehci_dbg() which
> calls dev_dbg() which discards it.
>
> Does it make sense now?
No. What happens if dynamic debug is enabled for one line that calls
dbg_port_buf() but not for another? There's no way to avoid the string
formatting in both lines, even though one of them discards the result.
Alan Stern
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-13 18:13 ` Alan Stern
@ 2012-04-13 19:03 ` Johannes Stezenbach
2012-04-13 19:40 ` Alan Stern
` (2 more replies)
0 siblings, 3 replies; 13+ messages in thread
From: Johannes Stezenbach @ 2012-04-13 19:03 UTC (permalink / raw)
To: Alan Stern; +Cc: Jason Baron, linux-kernel, linux-usb
On Fri, Apr 13, 2012 at 02:13:58PM -0400, Alan Stern wrote:
> On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
>
> > > But there is no such thing as dynamic debug for ehci, is there?
> > > There's a separate dynamic debug setting for each dev_dbg statement.
> > > So your ideal solution makes no sense.
> >
> > When CONFIG_DYNAMIC_DEBUG=y but ehci debug is disabled
>
> There is no such thing as ehci debug! So how can it be disabled?
> There's only an individual setting for each line of debugging code.
>
> > in /sys/kernel/debug/dynamic_debug/control, then
> > dbg_port() calls dbg_port_buf() which would
> > format the string, then calls ehci_dbg() which
> > calls dev_dbg() which discards it.
> >
> > Does it make sense now?
>
> No. What happens if dynamic debug is enabled for one line that calls
> dbg_port_buf() but not for another? There's no way to avoid the string
> formatting in both lines, even though one of them discards the result.
That's why I said in my initial mail:
Does dynamic debug offer an "is the message two lines below enabled" test?
What I meant is that dbg_port() could test if it
needs to call dbg_port_buf() for this call site.
Anyway, maybe the dbg_*_buf() are not called often enough to worry?
If you're OK with "#if defined(DEBUG) || defined(CONFIG_DYNAMIC_DEBUG)"
then maybe you should just do that?
Thanks
Johannes
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-13 19:03 ` Johannes Stezenbach
@ 2012-04-13 19:40 ` Alan Stern
2012-04-16 15:11 ` Alan Stern
2012-04-16 15:54 ` Jason Baron
2 siblings, 0 replies; 13+ messages in thread
From: Alan Stern @ 2012-04-13 19:40 UTC (permalink / raw)
To: Johannes Stezenbach; +Cc: Jason Baron, linux-kernel, linux-usb
On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
> > > Does it make sense now?
> >
> > No. What happens if dynamic debug is enabled for one line that calls
> > dbg_port_buf() but not for another? There's no way to avoid the string
> > formatting in both lines, even though one of them discards the result.
>
> That's why I said in my initial mail:
>
> Does dynamic debug offer an "is the message two lines below enabled" test?
>
> What I meant is that dbg_port() could test if it
> needs to call dbg_port_buf() for this call site.
Oh. As far as I know, that's not possible.
> Anyway, maybe the dbg_*_buf() are not called often enough to worry?
Probably not.
> If you're OK with "#if defined(DEBUG) || defined(CONFIG_DYNAMIC_DEBUG)"
> then maybe you should just do that?
Yes, that sounds best.
Alan Stern
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-13 19:03 ` Johannes Stezenbach
2012-04-13 19:40 ` Alan Stern
@ 2012-04-16 15:11 ` Alan Stern
2012-04-16 15:54 ` Jason Baron
2 siblings, 0 replies; 13+ messages in thread
From: Alan Stern @ 2012-04-16 15:11 UTC (permalink / raw)
To: Johannes Stezenbach; +Cc: Jason Baron, linux-kernel, linux-usb
On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
> Anyway, maybe the dbg_*_buf() are not called often enough to worry?
>
> If you're OK with "#if defined(DEBUG) || defined(CONFIG_DYNAMIC_DEBUG)"
> then maybe you should just do that?
Actually I'm pretty busy now. If you would like to submit a patch to
do this, it would be great.
Alan Stern
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-13 19:03 ` Johannes Stezenbach
2012-04-13 19:40 ` Alan Stern
2012-04-16 15:11 ` Alan Stern
@ 2012-04-16 15:54 ` Jason Baron
2012-04-16 16:41 ` Johannes Stezenbach
2 siblings, 1 reply; 13+ messages in thread
From: Jason Baron @ 2012-04-16 15:54 UTC (permalink / raw)
To: Johannes Stezenbach; +Cc: Alan Stern, linux-kernel, linux-usb
On Fri, Apr 13, 2012 at 09:03:11PM +0200, Johannes Stezenbach wrote:
> On Fri, Apr 13, 2012 at 02:13:58PM -0400, Alan Stern wrote:
> > On Fri, 13 Apr 2012, Johannes Stezenbach wrote:
> >
> > > > But there is no such thing as dynamic debug for ehci, is there?
> > > > There's a separate dynamic debug setting for each dev_dbg statement.
> > > > So your ideal solution makes no sense.
> > >
> > > When CONFIG_DYNAMIC_DEBUG=y but ehci debug is disabled
> >
> > There is no such thing as ehci debug! So how can it be disabled?
> > There's only an individual setting for each line of debugging code.
> >
> > > in /sys/kernel/debug/dynamic_debug/control, then
> > > dbg_port() calls dbg_port_buf() which would
> > > format the string, then calls ehci_dbg() which
> > > calls dev_dbg() which discards it.
> > >
> > > Does it make sense now?
> >
> > No. What happens if dynamic debug is enabled for one line that calls
> > dbg_port_buf() but not for another? There's no way to avoid the string
> > formatting in both lines, even though one of them discards the result.
>
> That's why I said in my initial mail:
>
> Does dynamic debug offer an "is the message two lines below enabled" test?
>
Sorry was away for a bit...
dynamic debug doesn't offer any is enabled test, its hidden from the
user. That said, in this case, you can delay the printing to the buffer
with:
diff --git a/drivers/usb/host/ehci-dbg.c b/drivers/usb/host/ehci-dbg.c
index d6d74d2..fd90ccd 100644
--- a/drivers/usb/host/ehci-dbg.c
+++ b/drivers/usb/host/ehci-dbg.c
@@ -254,7 +255,7 @@ dbg_command_buf (char *buf, unsigned len, const char *label, u32 command)
);
}
-static int
+static char *
dbg_port_buf (char *buf, unsigned len, const char *label, int port, u32 status)
{
char *sig;
@@ -267,7 +268,7 @@ dbg_port_buf (char *buf, unsigned len, const char *label, int port, u32 status)
default: sig = "?"; break;
}
- return scnprintf (buf, len,
+ scnprintf (buf, len,
"%s%sport:%d status %06x %d %s%s%s%s%s%s "
"sig=%s%s%s%s%s%s%s%s%s%s%s",
label, label [0] ? " " : "", port, status,
@@ -293,6 +294,8 @@ dbg_port_buf (char *buf, unsigned len, const char *label, int port, u32 status)
(status & PORT_PE) ? " PE" : "",
(status & PORT_CSC) ? " CSC" : "",
(status & PORT_CONNECT) ? " CONNECT" : "");
+
+ return buf;
}
#else
@@ -333,8 +336,7 @@ dbg_port_buf (char *buf, unsigned len, const char *label, int port, u32 status)
#define dbg_port(ehci, label, port, status) { \
char _buf [80]; \
- dbg_port_buf (_buf, sizeof _buf, label, port, status); \
- ehci_dbg (ehci, "%s\n", _buf); \
+ ehci_dbg (ehci, "%s\n", dbg_port_buf (_buf, sizeof _buf, label, port, status)); \
}
/*-------------------------------------------------------------------------*/
That seems to do what you want, at least with my compiler - gcc (GCC)
4.6.2 20111027 (Red Hat 4.6.2-1).
Thanks,
-Jason
^ permalink raw reply related [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-16 15:54 ` Jason Baron
@ 2012-04-16 16:41 ` Johannes Stezenbach
2012-04-16 17:15 ` Jason Baron
0 siblings, 1 reply; 13+ messages in thread
From: Johannes Stezenbach @ 2012-04-16 16:41 UTC (permalink / raw)
To: Jason Baron; +Cc: Alan Stern, linux-kernel, linux-usb
On Mon, Apr 16, 2012 at 11:54:24AM -0400, Jason Baron wrote:
> On Fri, Apr 13, 2012 at 09:03:11PM +0200, Johannes Stezenbach wrote:
> >
> > Does dynamic debug offer an "is the message two lines below enabled" test?
> >
>
> Sorry was away for a bit...
>
> dynamic debug doesn't offer any is enabled test, its hidden from the
> user. That said, in this case, you can delay the printing to the buffer
> with:
...
> + ehci_dbg (ehci, "%s\n", dbg_port_buf (_buf, sizeof _buf, label, port, status)); \
I think arguments are evaluated before dev_dbg is called so this
won't help.
Thanks
Johannes
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-16 16:41 ` Johannes Stezenbach
@ 2012-04-16 17:15 ` Jason Baron
2012-04-16 19:07 ` Johannes Stezenbach
0 siblings, 1 reply; 13+ messages in thread
From: Jason Baron @ 2012-04-16 17:15 UTC (permalink / raw)
To: Johannes Stezenbach; +Cc: Alan Stern, linux-kernel, linux-usb
On Mon, Apr 16, 2012 at 06:41:39PM +0200, Johannes Stezenbach wrote:
> On Mon, Apr 16, 2012 at 11:54:24AM -0400, Jason Baron wrote:
> > On Fri, Apr 13, 2012 at 09:03:11PM +0200, Johannes Stezenbach wrote:
> > >
> > > Does dynamic debug offer an "is the message two lines below enabled" test?
> > >
> >
> > Sorry was away for a bit...
> >
> > dynamic debug doesn't offer any is enabled test, its hidden from the
> > user. That said, in this case, you can delay the printing to the buffer
> > with:
> ...
> > + ehci_dbg (ehci, "%s\n", dbg_port_buf (_buf, sizeof _buf, label, port, status)); \
>
> I think arguments are evaluated before dev_dbg is called so this
> won't help.
>
>
I looked at the disassembly - and this argument was in fact *not* evaluated
before the call. So I think this approach is worthwhile.
Thanks,
-Jason
^ permalink raw reply [flat|nested] 13+ messages in thread
* Re: ehci dynamic debug problem
2012-04-16 17:15 ` Jason Baron
@ 2012-04-16 19:07 ` Johannes Stezenbach
0 siblings, 0 replies; 13+ messages in thread
From: Johannes Stezenbach @ 2012-04-16 19:07 UTC (permalink / raw)
To: Jason Baron; +Cc: Alan Stern, linux-kernel, linux-usb
On Mon, Apr 16, 2012 at 01:15:46PM -0400, Jason Baron wrote:
> On Mon, Apr 16, 2012 at 06:41:39PM +0200, Johannes Stezenbach wrote:
> > On Mon, Apr 16, 2012 at 11:54:24AM -0400, Jason Baron wrote:
> > > On Fri, Apr 13, 2012 at 09:03:11PM +0200, Johannes Stezenbach wrote:
> > > >
> > > > Does dynamic debug offer an "is the message two lines below enabled" test?
> > > >
> > >
> > > Sorry was away for a bit...
> > >
> > > dynamic debug doesn't offer any is enabled test, its hidden from the
> > > user. That said, in this case, you can delay the printing to the buffer
> > > with:
> > ...
> > > + ehci_dbg (ehci, "%s\n", dbg_port_buf (_buf, sizeof _buf, label, port, status)); \
> >
> > I think arguments are evaluated before dev_dbg is called so this
> > won't help.
>
> I looked at the disassembly - and this argument was in fact *not* evaluated
> before the call. So I think this approach is worthwhile.
OK, I was in a hurry before but now that I looked at
dynamic_dev_dbg() definition in include/linux/dynamic_debug.h
I see that it works. IMHO it's a good solution.
Thank you,
Johannes
^ permalink raw reply [flat|nested] 13+ messages in thread
end of thread, other threads:[~2012-04-16 19:08 UTC | newest]
Thread overview: 13+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-04-13 8:56 ehci dynamic debug problem Johannes Stezenbach
2012-04-13 14:35 ` Alan Stern
2012-04-13 14:57 ` Johannes Stezenbach
2012-04-13 15:19 ` Alan Stern
2012-04-13 17:41 ` Johannes Stezenbach
2012-04-13 18:13 ` Alan Stern
2012-04-13 19:03 ` Johannes Stezenbach
2012-04-13 19:40 ` Alan Stern
2012-04-16 15:11 ` Alan Stern
2012-04-16 15:54 ` Jason Baron
2012-04-16 16:41 ` Johannes Stezenbach
2012-04-16 17:15 ` Jason Baron
2012-04-16 19:07 ` Johannes Stezenbach
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).