Re: Help adding trace events to xHCI
On Thu, 2013-07-11 at 15:29 -0400, Steven Rostedt wrote: Note that there's no easy way to dynamically allocate the right amount of space in the ringbuffer, or at least I haven't found one. We therefore have a static size, which is somewhat inefficient. Can you add a helper function? If these trace events can't nest (one in interrupt context and another in normal context with interrupts enabled), then you can just allocate a per-cpu buffer and store the string in that, and then move the string into the buffer. In my situation personally, I can't, because I can have them in interrupt and regular context (with interrupts enabled). My original though here was that we should be able to reserve (maximum) space on the per-CPU buffer, and then relinquish some of it after the tracepoint was written to the data, but I never had the time to check if that was possible to implement. It would make it a little inefficient at page boundaries, but that seems OK given that our maximum size is only ~100 bytes or so now. johannes -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On Fri, 2013-07-26 at 11:19 +0200, Johannes Berg wrote:
My original though here was that we should be able to reserve (maximum)
space on the per-CPU buffer, and then relinquish some of it after the
tracepoint was written to the data, but I never had the time to check if
that was possible to implement. It would make it a little inefficient at
page boundaries, but that seems OK given that our maximum size is only
~100 bytes or so now.
Yes that would be trivial to implement. If the max buffer is ~100 bytes,
allocate 256 byte buffers per cpu. Also have a per cpu index, and then
have something like this:
index = local_add_return(this_cpu_ptr(trace_index), len);
if (index = MAX_BUF) {
/* write tracepoint with failed buffer */
local_sub(this_cpu_ptr(trace_index));
return;
}
index -= len;
memcpy(this_cpu_ptr(trace_buf) + index, string, len);
/* write tracepoint with trace_buf */
local_sub(this_cpu_ptr(trace_index), len);
This way the trace_buf will work like a stack allocator. The
local_add_return() will reserve the space in the buffer such that if an
interrupt were to come in, it would allocate after that space. The check
for MAX_BUF tests for the case that the buffer was too big and had to
bail. Still trace that event to let the user (yourself) know you need a
bigger buffer.
-- Steve
--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On Fri, 2013-07-26 at 08:28 -0400, Steven Rostedt wrote: My original though here was that we should be able to reserve (maximum) space on the per-CPU buffer, and then relinquish some of it after the tracepoint was written to the data, but I never had the time to check if that was possible to implement. It would make it a little inefficient at page boundaries, but that seems OK given that our maximum size is only ~100 bytes or so now. Yes that would be trivial to implement. If the max buffer is ~100 bytes, allocate 256 byte buffers per cpu. Also have a per cpu index, and then have something like this: [snip] Ah, yes, that'd work. I was considering putting it into the trace event handling itself so I don't have to allocate those buffers and put the handling into every tracepoint, but I don't know how that'd work with interrupts coming in. If we assume that interrupts coming in in the middle of a tracepoint should be rare, we could do something like * allocate max buffer in on the tracing ringbuffer page * write data into it * if no interrupt came in, reduce reservation but I'm not sure how to implement step 3 :) johannes -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On Fri, 2013-07-26 at 15:06 +0200, Johannes Berg wrote: On Fri, 2013-07-26 at 08:28 -0400, Steven Rostedt wrote: Ah, yes, that'd work. I was considering putting it into the trace event handling itself so I don't have to allocate those buffers and put the handling into every tracepoint, but I don't know how that'd work with interrupts coming in. If you create helper functions, it shouldn't be too hard. If we assume that interrupts coming in in the middle of a tracepoint should be rare, we could do something like * allocate max buffer in on the tracing ringbuffer page * write data into it * if no interrupt came in, reduce reservation but I'm not sure how to implement step 3 :) It's possible to reduce the ring buffer, it's just not implemented. I'm not sure I want to do that either. Interrupts coming in is not so rare as it can be any interrupt being traced. This means your tracepoints will likely waste a lot of buffer space if you are tracing interrupts as well. That said, I can probably implement a reduce feature of the ring buffer if needed. -- Steve -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On Fri, 2013-07-26 at 09:17 -0400, Steven Rostedt wrote: On Fri, 2013-07-26 at 15:06 +0200, Johannes Berg wrote: On Fri, 2013-07-26 at 08:28 -0400, Steven Rostedt wrote: Ah, yes, that'd work. I was considering putting it into the trace event handling itself so I don't have to allocate those buffers and put the handling into every tracepoint, but I don't know how that'd work with interrupts coming in. If you create helper functions, it shouldn't be too hard. True, and I could even export them somewhere to share the buffers between all the different subsystems that might use this. If we assume that interrupts coming in in the middle of a tracepoint should be rare, we could do something like * allocate max buffer in on the tracing ringbuffer page * write data into it * if no interrupt came in, reduce reservation but I'm not sure how to implement step 3 :) It's possible to reduce the ring buffer, it's just not implemented. I'm not sure I want to do that either. Interrupts coming in is not so rare as it can be any interrupt being traced. This means your tracepoints will likely waste a lot of buffer space if you are tracing interrupts as well. Well, right now I can live with allocation 110 bytes for each tracepoint, this would just optimise it down. If I was in the middle of writing one such event while an interrupt came in, I'd not be able to reduce the ring-buffer allocation again. I doubt that an interrupt would come in much of the time between allocating the new event and deallocating it partially. The more difficult question would seem to be whether or not we can reliably detect an interrupt having written another event. Also, this would save the memcpy() your scheme had. Anyway, I'm fine with the current status quo, but if more people want to trace variable length things like formatted strings I think it might make sense to add some way of making that more efficient. johannes -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On Fri, 2013-07-26 at 15:45 +0200, Johannes Berg wrote: Well, right now I can live with allocation 110 bytes for each tracepoint, this would just optimise it down. If I was in the middle of writing one such event while an interrupt came in, I'd not be able to reduce the ring-buffer allocation again. I doubt that an interrupt would come in much of the time between allocating the new event and deallocating it partially. The more difficult question would seem to be whether or not we can reliably detect an interrupt having written another event. Hmm, you may be convincing me ;-) As it just allocates the max anyway, this feature will actually help. Don't worry about the detection of interrupt, it already does that with the discard event. It wouldn't be that hard to extend that into a reduction too. -- Steve -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
* Mark Wielaard (m...@redhat.com) wrote: Hi Mathieu, On Fri, Jul 12, 2013 at 01:08:28PM -0400, Mathieu Desnoyers wrote: * Sarah Sharp (sarah.a.sh...@linux.intel.com) wrote: Thanks for the suggestion. I'm not familiar with all the userspace tools for trace events, so I didn't know about the command parser. Is there documentation or a list of resources for all the userspace trace event plugins? If so, can you give us a pointer to it? You might want to try out LTTng-UST. It provides TRACEPOINT_EVENT() and tracepoint() for user-space instrumentation. See: - https://lttng.org/files/doc/man-pages/man3/lttng-ust.3.html Is that build on the sys/sdt.h ust probe points as embedded in glibc for example that gdb and systemtap use to access user space trace points? LTTng-UST tracepoints are not built on sdt.h, but they can optionally emit sdt.h instrumentation. All you need to do is run: ./configure --with-sdt when configuring lttng-ust, and after a make install, sdt.h STAP_PROBEV() will be emitted whenever a lttng-ust tracepoint() macro is used in the system. Can tools use lttng-ust and sys/sdt.h tracepoints interchangeably by parsing the ELF notes described in http://sourceware.org/systemtap/wiki/UserSpaceProbeImplementation Since lttng-ust tracepoints emit sdt.h instrumentation, yes. However, please note that the reverse is not possible: sdt.h instrumentation does not allow tracing with LTTng-UST. Thanks, Mathieu Thanks, Mark -- Mathieu Desnoyers EfficiOS Inc. http://www.efficios.com -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On Fri, Jul 12, 2013 at 12:55:43PM -0400, Steven Rostedt wrote: On Fri, 2013-07-12 at 09:41 -0700, Sarah Sharp wrote: On Fri, Jul 12, 2013 at 07:25:59AM +0300, Kalle Valo wrote: Thanks for the suggestion. I'm not familiar with all the userspace tools for trace events, so I didn't know about the command parser. Is there documentation or a list of resources for all the userspace trace event plugins? If so, can you give us a pointer to it? Currently the plugins only exist in trace-cmd. But there's going to be work done to get them into the kernel tools directory. I was just talking with Jiri about this today. Perf will require it. hi, I made initial backport but got distracted.. ;-) I'll refresh those patches and resend them out soon.. jirka -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On Fri, Jul 12, 2013 at 07:25:59AM +0300, Kalle Valo wrote: Sarah Sharp sarah.a.sh...@linux.intel.com writes: My initial list of specific trace points was something like: 1. xHCI host initialization and shutdown 2. xHCI memory allocation (dynamic ring resizing, structure alloc, etc) 3. A few individual xHCI host controller command tracepoints: * status only for all completed commands * Address Device command status and output * Configure Endpoint and Evaluate Context output * individual trace points for other xHCI commands 4. Tracepoints for all USB transfer types: * Control TX output (only for non-successful transfers) * Bulk TX * Interrupt TX * Isoc TX 5. URB cancellation And probably more. Basically, I want to be able to control what gets printed, based on where I think the xHCI bug might be. Does that sound reasonable? Instead of individual trace points for command I would recommend to consider just pushing the whole command buffer to the trace point and parse the command in trace-cmd plugin in user space. Kernel code would be simpler that way. Thanks for the suggestion. I'm not familiar with all the userspace tools for trace events, so I didn't know about the command parser. Is there documentation or a list of resources for all the userspace trace event plugins? If so, can you give us a pointer to it? Sarah Sharp -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On Fri, 2013-07-12 at 09:41 -0700, Sarah Sharp wrote: On Fri, Jul 12, 2013 at 07:25:59AM +0300, Kalle Valo wrote: Thanks for the suggestion. I'm not familiar with all the userspace tools for trace events, so I didn't know about the command parser. Is there documentation or a list of resources for all the userspace trace event plugins? If so, can you give us a pointer to it? Currently the plugins only exist in trace-cmd. But there's going to be work done to get them into the kernel tools directory. I was just talking with Jiri about this today. Perf will require it. trace-cmd repo is here: git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/trace-cmd.git -- Steve -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
* Sarah Sharp (sarah.a.sh...@linux.intel.com) wrote: On Fri, Jul 12, 2013 at 07:25:59AM +0300, Kalle Valo wrote: Sarah Sharp sarah.a.sh...@linux.intel.com writes: My initial list of specific trace points was something like: 1. xHCI host initialization and shutdown 2. xHCI memory allocation (dynamic ring resizing, structure alloc, etc) 3. A few individual xHCI host controller command tracepoints: * status only for all completed commands * Address Device command status and output * Configure Endpoint and Evaluate Context output * individual trace points for other xHCI commands 4. Tracepoints for all USB transfer types: * Control TX output (only for non-successful transfers) * Bulk TX * Interrupt TX * Isoc TX 5. URB cancellation And probably more. Basically, I want to be able to control what gets printed, based on where I think the xHCI bug might be. Does that sound reasonable? Instead of individual trace points for command I would recommend to consider just pushing the whole command buffer to the trace point and parse the command in trace-cmd plugin in user space. Kernel code would be simpler that way. Thanks for the suggestion. I'm not familiar with all the userspace tools for trace events, so I didn't know about the command parser. Is there documentation or a list of resources for all the userspace trace event plugins? If so, can you give us a pointer to it? (CCing lttng-dev) You might want to try out LTTng-UST. It provides TRACEPOINT_EVENT() and tracepoint() for user-space instrumentation. See: - https://lttng.org/files/doc/man-pages/man3/lttng-ust.3.html - http://lttng.org Thanks, Mathieu Sarah Sharp -- To unsubscribe from this list: send the line unsubscribe linux-trace-users in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html -- Mathieu Desnoyers EfficiOS Inc. http://www.efficios.com -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
Sarah Sharp sarah.a.sh...@linux.intel.com writes: On Fri, Jul 12, 2013 at 07:25:59AM +0300, Kalle Valo wrote: Instead of individual trace points for command I would recommend to consider just pushing the whole command buffer to the trace point and parse the command in trace-cmd plugin in user space. Kernel code would be simpler that way. Thanks for the suggestion. I'm not familiar with all the userspace tools for trace events, so I didn't know about the command parser. Is there documentation or a list of resources for all the userspace trace event plugins? If so, can you give us a pointer to it? For ath6kl I started writing (but did not finish yet) a simple python plugin for trace-cmd. I really like the idea of implementing of implementing the parser with python, it's so much faster and more convenient. I haven't published the plugin yet so that's not going to help you right now. But trace-cmd documentation about python plugins should give some ideas how to use python: https://git.kernel.org/cgit/linux/kernel/git/rostedt/trace-cmd.git/tree/Documentation/README.PythonPlugin And as usual, Johannes is a good source of information ;) -- Kalle Valo -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
Hi Mathieu, On Fri, Jul 12, 2013 at 01:08:28PM -0400, Mathieu Desnoyers wrote: * Sarah Sharp (sarah.a.sh...@linux.intel.com) wrote: Thanks for the suggestion. I'm not familiar with all the userspace tools for trace events, so I didn't know about the command parser. Is there documentation or a list of resources for all the userspace trace event plugins? If so, can you give us a pointer to it? You might want to try out LTTng-UST. It provides TRACEPOINT_EVENT() and tracepoint() for user-space instrumentation. See: - https://lttng.org/files/doc/man-pages/man3/lttng-ust.3.html Is that build on the sys/sdt.h ust probe points as embedded in glibc for example that gdb and systemtap use to access user space trace points? Can tools use lttng-ust and sys/sdt.h tracepoints interchangeably by parsing the ELF notes described in http://sourceware.org/systemtap/wiki/UserSpaceProbeImplementation Thanks, Mark -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
[also adding Steven, he's the tracing expert after all :-)]
Hi Xenia, Sarah, all,
(Mentors and wireless folks, we're struggling a bit with adding trace
events to the xHCI USB host controller driver. I'm trying to look at
the ath6kl driver trace events as an example. We could use some help
and/or advice.)
Those were in turn modelled on mac80211, cfg80211 and/or iwlwifi, I
think; might be worth also looking there. In general though, it's all
pretty similar.
lets say that we want the tracepoint function to have the prototype:
void trace_cmd_address_device(const char *fmt, ...).
I'm not sure this is possible. I think we (wireless) do this with
void trace_cmd_address_device(struct va_format *vaf)
instead only.
Note that there's no easy way to dynamically allocate the right amount
of space in the ringbuffer, or at least I haven't found one. We
therefore have a static size, which is somewhat inefficient.
The ath driver defines a new trace event class, ath6kl_log_event.
Various types of tracepoints, like trace_ath6kl_log_warn, use that event
class. Wrappers like ath6kl_warn() call those trace points, passing it
a struct va_format on the stack:
int ath6kl_warn(const char *fmt, ...)
{
struct va_format vaf = {
.fmt = fmt,
};
va_list args;
int ret;
va_start(args, fmt);
vaf.va = args;
ret = ath6kl_printk(KERN_WARNING, %pV, vaf);
Note also on older kernels you used to have to do va_copy() here because
%pV didn't do it by itself. Guess you don't care though, but I
sometimes have to worry about backporting :-)
int xhci_debug_address(const char *fmt, ...)
This confuses me somewhat -- why is it called xhci_debug_address()
when it takes arbitrary parameters? Where's the address part?
DEFINE_EVENT(xhci_log_event, xhci_dbg_address,
TP_PROTO(struct va_format *vaf),
TP_ARGS(vaf)
);
DECLARE_EVENT_CLASS(xhci_log_event,
TP_PROTO(struct va_format *vaf),
TP_ARGS(vaf),
TP_STRUCT__entry(
__dynamic_array(char, msg, ATH6KL_MSG_MAX)
Should probably not be ATH6KL_MSG_MAX :-)
And this is what I talked about before -- it always allocates the max in
the ringbuffer even for really short messages.
And then code in xhci_address_device() in drivers/usb/host/xhci.c can do
things like:
xhci_debug_address(xhci, Bad Slot ID %d\n, udev-slot_id);
Otherwise this looks about right (you have an xhci argument you didn't
declare above, but this is obviously pseudo-code only)
And we can define similar trace event classes for the various xHCI
commands or ring debugging, so that we can enable or disable trace
points individually for different parts of the xHCI driver.
I think it'd be worth (also) doing more specific tracepoints instead
though.
I don't really know what xhci does, but I suppose it has register
read/write, maybe packet (urb?) submissions etc. so something like the
iwlwifi_io system in drivers/net/wireless/iwlwifi/iwl-devtrace.h might
(also) be (more) useful. In iwlwifi I have tracing for
* IO accesses interrupt notifications/reasons
* commands and TX packets submitted to the device
* notifications/RX packets received from the device
* previously existing debug messages
The message tracing was really more of an after-thought in iwlwifi (and
ath6kl as well I guess) because we already had a lot of debug messages
and capturing it all together can be useful.
However, tracing all the debug messages is actually fairly expensive, I
think in part because of the string formatting and in part because of
the always-max allocations in the ringbuffer.
That would have worked if the tracepoint was just :
void trace_cmd_address_device(const char *fmt, ...)
{
if (trace event cmd_address_device is enabled) do {
(void(*)(const char *fmt, ...)) callback ((const
char *)fmt);
}
}
I'm not really sure what the whole callback() part is about?
Are you trying to use the tracepoint is enabled to do something
unrelated to the tracing? I'm guessing that's _possible_, but I wouldn't
recommend it.
I'm actually wondering if the call to ath6kl_printk is somehow necessary
in order to be able to pass arguments on the stack.
I don't think it is, but formatting the messages *only* for tracing
seems a bit odd?
Hth,
johannes
--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On 07/11/2013 06:20 PM, Sarah Sharp wrote:
On Mon, Jul 08, 2013 at 09:17:59PM +0300, Xenia Ragiadakou wrote:
But when there are other function calls before the callback call, I don't
no why but i cannot track anymore the position of the args following the
fmt argumenent in the stack with the pointer to fmt.
I'm actually wondering if the call to ath6kl_printk is somehow necessary
in order to be able to pass arguments on the stack. Perhaps you should
try defining a similar function for xHCI and see if that helps?
The ath6klk_printk() is not related to the trace function. It is a
separate code path to get the message in the kernel log. I have seen
these constructs before (and implemented it in brcmfmac) but it seems
not very efficient when tracing as the printk can affect run-time behaviour.
int ath6kl_printk(const char *level, const char *fmt, ...)
{
struct va_format vaf;
va_list args;
int rtn;
va_start(args, fmt);
vaf.fmt = fmt;
vaf.va = args;
rtn = printk(%sath6kl: %pV, level, vaf);
va_end(args);
return rtn;
}
EXPORT_SYMBOL(ath6kl_printk);
Anyway, something dirty like that will not enter the kernel but i will try
to do stack debugging on an example program to see why that happens.
I would suggest just copy-pasting parts of the ath6kl trace code into
the xHCI driver, and changing one of the xhci_dbg() calls to use that
code, and see if it works. If it doesn't work, send out an RFC patch
(using the Cc list I've used), and we'll try to figure out what's going
wrong.
The biggest challenge in adding tracepoints is identifying what you want
to trace. While tracing debug messages can be convenient the real
strength is in tracing code artifacts like for USB the thing that comes
to my mind first is defining tracepoint for the urb and there are
probably other internals that are informational.
Regards,
Arend
--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
On Thu, Jul 11, 2013 at 07:08:53PM +0200, Johannes Berg wrote:
[also adding Steven, he's the tracing expert after all :-)]
Hi Xenia, Sarah, all,
(Mentors and wireless folks, we're struggling a bit with adding trace
events to the xHCI USB host controller driver. I'm trying to look at
the ath6kl driver trace events as an example. We could use some help
and/or advice.)
Those were in turn modelled on mac80211, cfg80211 and/or iwlwifi, I
think; might be worth also looking there. In general though, it's all
pretty similar.
lets say that we want the tracepoint function to have the prototype:
void trace_cmd_address_device(const char *fmt, ...).
I'm not sure this is possible. I think we (wireless) do this with
void trace_cmd_address_device(struct va_format *vaf)
instead only.
Note that there's no easy way to dynamically allocate the right amount
of space in the ringbuffer, or at least I haven't found one. We
therefore have a static size, which is somewhat inefficient.
Yes, that does look inefficient. Would it make sense to add a couple
different trace event classes for different sized buffers, and call
those trace classes conditionally, based on the size of the formatted
string? Or would that be too much of a mess.
Either way, it's only inefficient when trace events are turned on. We
don't expect xHCI debugging to be enabled by users very often. I do
expect that there will be a lot of debugging when it gets turned on.
Can userspace increase the size of the ring buffer? How much space do
we have by default?
The ath driver defines a new trace event class, ath6kl_log_event.
Various types of tracepoints, like trace_ath6kl_log_warn, use that event
class. Wrappers like ath6kl_warn() call those trace points, passing it
a struct va_format on the stack:
int ath6kl_warn(const char *fmt, ...)
{
struct va_format vaf = {
.fmt = fmt,
};
va_list args;
int ret;
va_start(args, fmt);
vaf.va = args;
ret = ath6kl_printk(KERN_WARNING, %pV, vaf);
Note also on older kernels you used to have to do va_copy() here because
%pV didn't do it by itself. Guess you don't care though, but I
sometimes have to worry about backporting :-)
The trace events are unlikely to get backported, so I'm not concerned
about that.
int xhci_debug_address(const char *fmt, ...)
This confuses me somewhat -- why is it called xhci_debug_address()
when it takes arbitrary parameters? Where's the address part?
It's debugging the xHCI Address command output. Depending on the status
of the command, we print different statement in the xHCI code. E.g. we
print when the command times out, or finishes with an error status
because there was a USB transfer error on the bus.
We can work on better names later. :)
DEFINE_EVENT(xhci_log_event, xhci_dbg_address,
TP_PROTO(struct va_format *vaf),
TP_ARGS(vaf)
);
DECLARE_EVENT_CLASS(xhci_log_event,
TP_PROTO(struct va_format *vaf),
TP_ARGS(vaf),
TP_STRUCT__entry(
__dynamic_array(char, msg, ATH6KL_MSG_MAX)
Should probably not be ATH6KL_MSG_MAX :-)
Yes.
And this is what I talked about before -- it always allocates the max in
the ringbuffer even for really short messages.
Noted.
And then code in xhci_address_device() in drivers/usb/host/xhci.c can do
things like:
xhci_debug_address(xhci, Bad Slot ID %d\n, udev-slot_id);
Otherwise this looks about right (you have an xhci argument you didn't
declare above, but this is obviously pseudo-code only)
And we can define similar trace event classes for the various xHCI
commands or ring debugging, so that we can enable or disable trace
points individually for different parts of the xHCI driver.
I think it'd be worth (also) doing more specific tracepoints instead
though.
I don't really know what xhci does, but I suppose it has register
read/write, maybe packet (urb?) submissions etc. so something like the
iwlwifi_io system in drivers/net/wireless/iwlwifi/iwl-devtrace.h might
(also) be (more) useful. In iwlwifi I have tracing for
* IO accesses interrupt notifications/reasons
* commands and TX packets submitted to the device
* notifications/RX packets received from the device
* previously existing debug messages
My initial list of specific trace points was something like:
1. xHCI host initialization and shutdown
2. xHCI memory allocation (dynamic ring resizing, structure alloc, etc)
3. A few individual xHCI host controller command tracepoints:
* status only for all completed commands
* Address Device command status and output
* Configure Endpoint and Evaluate Context output
* individual trace points for other xHCI commands
4. Tracepoints for all USB transfer types:
* Control TX output (only for non-successful transfers)
* Bulk TX
* Interrupt TX
* Isoc TX
5. URB
Re: Help adding trace events to xHCI
On Thu, 2013-07-11 at 19:08 +0200, Johannes Berg wrote: lets say that we want the tracepoint function to have the prototype: void trace_cmd_address_device(const char *fmt, ...). I'm not sure this is possible. I think we (wireless) do this with void trace_cmd_address_device(struct va_format *vaf) instead only. Note that there's no easy way to dynamically allocate the right amount of space in the ringbuffer, or at least I haven't found one. We therefore have a static size, which is somewhat inefficient. Can you add a helper function? If these trace events can't nest (one in interrupt context and another in normal context with interrupts enabled), then you can just allocate a per-cpu buffer and store the string in that, and then move the string into the buffer. vsnprintf(this_cpu_ptr(trace_buf), MAX_BUF_LEN, fmt, va); __assign_str(str, trace_buf); You could even use the reg, unreg, methods for TRACE_EVENT_FN() that will allocate the buffers when the tracepoint is created. This will mean that you don't waste memory when not tracing. -- Steve -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
Johannes Berg johan...@sipsolutions.net writes: (Mentors and wireless folks, we're struggling a bit with adding trace events to the xHCI USB host controller driver. I'm trying to look at the ath6kl driver trace events as an example. We could use some help and/or advice.) Those were in turn modelled on mac80211, cfg80211 and/or iwlwifi, I think; might be worth also looking there. In general though, it's all pretty similar. Correct, I used your code as example. The message tracing was really more of an after-thought in iwlwifi (and ath6kl as well I guess) because we already had a lot of debug messages and capturing it all together can be useful. However, tracing all the debug messages is actually fairly expensive, I think in part because of the string formatting and in part because of the always-max allocations in the ringbuffer. The reason why added message tracing to ath6kl was that I wanted to combine wpasupplicant, cfg80211 and ath6kl debug messages all into file with synchronised timestamps. In this case I wasn't actually concerned about performance at all. -- Kalle Valo -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: Help adding trace events to xHCI
Sarah Sharp sarah.a.sh...@linux.intel.com writes: My initial list of specific trace points was something like: 1. xHCI host initialization and shutdown 2. xHCI memory allocation (dynamic ring resizing, structure alloc, etc) 3. A few individual xHCI host controller command tracepoints: * status only for all completed commands * Address Device command status and output * Configure Endpoint and Evaluate Context output * individual trace points for other xHCI commands 4. Tracepoints for all USB transfer types: * Control TX output (only for non-successful transfers) * Bulk TX * Interrupt TX * Isoc TX 5. URB cancellation And probably more. Basically, I want to be able to control what gets printed, based on where I think the xHCI bug might be. Does that sound reasonable? Instead of individual trace points for command I would recommend to consider just pushing the whole command buffer to the trace point and parse the command in trace-cmd plugin in user space. Kernel code would be simpler that way. -- Kalle Valo -- To unsubscribe from this list: send the line unsubscribe linux-usb in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
