This patch fixes two issues reported with ksym tracer, seen after
removal of a symbol from the tracer i) Concatenation of trace logs
into a single line ii) Machine stall seen when logs are viewed
using 'trace_pipe'.
Known issue: Upon removal, 'cat trace_pipe' (without any preceding
command and any further output in the trace buffer) responds to
SIGTERM quickly but only after an indeterminate amount of delay
for SIGINT.
Signed-off-by: K.Prasad <[email protected]>
---
kernel/trace/trace.h | 12 +++++++++---
kernel/trace/trace_ksym.c | 11 ++++-------
2 files changed, 13 insertions(+), 10 deletions(-)
Index: linux-2.6-tip.hbkpt/kernel/trace/trace_ksym.c
===================================================================
--- linux-2.6-tip.hbkpt.orig/kernel/trace/trace_ksym.c
+++ linux-2.6-tip.hbkpt/kernel/trace/trace_ksym.c
@@ -71,7 +71,7 @@ void ksym_hbp_handler(struct hw_breakpoi
{
struct ring_buffer_event *event;
struct trace_array *tr;
- struct trace_ksym *entry;
+ struct trace_ksym_rb *entry;
int pc;
if (!ksym_tracing_enabled)
@@ -87,7 +87,7 @@ void ksym_hbp_handler(struct hw_breakpoi
entry = ring_buffer_event_data(event);
strlcpy(entry->ksym_name, hbp->info.name, KSYM_SYMBOL_LEN);
- entry->ksym_hbp = hbp;
+ memcpy(&(entry->ksym_hbp), hbp, sizeof(struct hw_breakpoint));
entry->ip = instruction_pointer(regs);
strlcpy(entry->p_name, current->comm, TASK_COMM_LEN);
#ifdef CONFIG_PROFILE_KSYM_TRACER
@@ -380,7 +380,7 @@ static enum print_line_t ksym_trace_outp
{
struct trace_entry *entry = iter->ent;
struct trace_seq *s = &iter->seq;
- struct trace_ksym *field;
+ struct trace_ksym_rb *field;
char str[KSYM_SYMBOL_LEN];
int ret;
@@ -394,17 +394,14 @@ static enum print_line_t ksym_trace_outp
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
- switch (field->ksym_hbp->info.type) {
+ switch (field->ksym_hbp.info.type) {
case HW_BREAKPOINT_WRITE:
ret = trace_seq_printf(s, " W ");
break;
case HW_BREAKPOINT_RW:
ret = trace_seq_printf(s, " RW ");
break;
- default:
- return TRACE_TYPE_PARTIAL_LINE;
}
-
if (!ret)
return TRACE_TYPE_PARTIAL_LINE;
Index: linux-2.6-tip.hbkpt/kernel/trace/trace.h
===================================================================
--- linux-2.6-tip.hbkpt.orig/kernel/trace/trace.h
+++ linux-2.6-tip.hbkpt/kernel/trace/trace.h
@@ -216,15 +216,21 @@ struct syscall_trace_exit {
extern int process_new_ksym_entry(char *ksymname, int op, unsigned long addr);
struct trace_ksym {
- struct trace_entry ent;
struct hw_breakpoint *ksym_hbp;
unsigned long ksym_addr;
- unsigned long ip;
#ifdef CONFIG_PROFILE_KSYM_TRACER
unsigned long counter;
#endif
struct hlist_node ksym_hlist;
char ksym_name[KSYM_NAME_LEN];
+};
+
+/* Ring buffer's copy of the breakpoint data */
+struct trace_ksym_rb {
+ struct trace_entry ent;
+ struct hw_breakpoint ksym_hbp;
+ unsigned long ip;
+ char ksym_name[KSYM_NAME_LEN];
char p_name[TASK_COMM_LEN];
};
@@ -343,7 +349,7 @@ extern void __ftrace_bad_type(void);
TRACE_SYSCALL_ENTER); \
IF_ASSIGN(var, ent, struct syscall_trace_exit, \
TRACE_SYSCALL_EXIT); \
- IF_ASSIGN(var, ent, struct trace_ksym, TRACE_KSYM); \
+ IF_ASSIGN(var, ent, struct trace_ksym_rb, TRACE_KSYM); \
__ftrace_bad_type(); \
} while (0)
On Fri, Jun 19, 2009 at 10:54:53PM +0530, K.Prasad wrote:
> This patch fixes two issues reported with ksym tracer, seen after
> removal of a symbol from the tracer i) Concatenation of trace logs
> into a single line ii) Machine stall seen when logs are viewed
> using 'trace_pipe'.
>
> Known issue: Upon removal, 'cat trace_pipe' (without any preceding
> command and any further output in the trace buffer) responds to
> SIGTERM quickly but only after an indeterminate amount of delay
> for SIGINT.
>
> Signed-off-by: K.Prasad <[email protected]>
> ---
> kernel/trace/trace.h | 12 +++++++++---
> kernel/trace/trace_ksym.c | 11 ++++-------
> 2 files changed, 13 insertions(+), 10 deletions(-)
>
> Index: linux-2.6-tip.hbkpt/kernel/trace/trace_ksym.c
> ===================================================================
> --- linux-2.6-tip.hbkpt.orig/kernel/trace/trace_ksym.c
> +++ linux-2.6-tip.hbkpt/kernel/trace/trace_ksym.c
> @@ -71,7 +71,7 @@ void ksym_hbp_handler(struct hw_breakpoi
> {
> struct ring_buffer_event *event;
> struct trace_array *tr;
> - struct trace_ksym *entry;
> + struct trace_ksym_rb *entry;
> int pc;
>
> if (!ksym_tracing_enabled)
> @@ -87,7 +87,7 @@ void ksym_hbp_handler(struct hw_breakpoi
>
> entry = ring_buffer_event_data(event);
> strlcpy(entry->ksym_name, hbp->info.name, KSYM_SYMBOL_LEN);
> - entry->ksym_hbp = hbp;
> + memcpy(&(entry->ksym_hbp), hbp, sizeof(struct hw_breakpoint));
That looks wasteful. You only need the type from the arch_hw_breakpoint
and there you copy the whole generic breakpoint.
Frederic.
> entry->ip = instruction_pointer(regs);
> strlcpy(entry->p_name, current->comm, TASK_COMM_LEN);
> #ifdef CONFIG_PROFILE_KSYM_TRACER
> @@ -380,7 +380,7 @@ static enum print_line_t ksym_trace_outp
> {
> struct trace_entry *entry = iter->ent;
> struct trace_seq *s = &iter->seq;
> - struct trace_ksym *field;
> + struct trace_ksym_rb *field;
> char str[KSYM_SYMBOL_LEN];
> int ret;
>
> @@ -394,17 +394,14 @@ static enum print_line_t ksym_trace_outp
> if (!ret)
> return TRACE_TYPE_PARTIAL_LINE;
>
> - switch (field->ksym_hbp->info.type) {
> + switch (field->ksym_hbp.info.type) {
> case HW_BREAKPOINT_WRITE:
> ret = trace_seq_printf(s, " W ");
> break;
> case HW_BREAKPOINT_RW:
> ret = trace_seq_printf(s, " RW ");
> break;
> - default:
> - return TRACE_TYPE_PARTIAL_LINE;
> }
> -
> if (!ret)
> return TRACE_TYPE_PARTIAL_LINE;
>
> Index: linux-2.6-tip.hbkpt/kernel/trace/trace.h
> ===================================================================
> --- linux-2.6-tip.hbkpt.orig/kernel/trace/trace.h
> +++ linux-2.6-tip.hbkpt/kernel/trace/trace.h
> @@ -216,15 +216,21 @@ struct syscall_trace_exit {
> extern int process_new_ksym_entry(char *ksymname, int op, unsigned long addr);
>
> struct trace_ksym {
> - struct trace_entry ent;
> struct hw_breakpoint *ksym_hbp;
> unsigned long ksym_addr;
> - unsigned long ip;
> #ifdef CONFIG_PROFILE_KSYM_TRACER
> unsigned long counter;
> #endif
> struct hlist_node ksym_hlist;
> char ksym_name[KSYM_NAME_LEN];
> +};
> +
> +/* Ring buffer's copy of the breakpoint data */
> +struct trace_ksym_rb {
> + struct trace_entry ent;
> + struct hw_breakpoint ksym_hbp;
> + unsigned long ip;
> + char ksym_name[KSYM_NAME_LEN];
> char p_name[TASK_COMM_LEN];
> };
>
> @@ -343,7 +349,7 @@ extern void __ftrace_bad_type(void);
> TRACE_SYSCALL_ENTER); \
> IF_ASSIGN(var, ent, struct syscall_trace_exit, \
> TRACE_SYSCALL_EXIT); \
> - IF_ASSIGN(var, ent, struct trace_ksym, TRACE_KSYM); \
> + IF_ASSIGN(var, ent, struct trace_ksym_rb, TRACE_KSYM); \
> __ftrace_bad_type(); \
> } while (0)
>
>
On Sat, Jun 20, 2009 at 01:03:49AM +0200, Frederic Weisbecker wrote:
> On Fri, Jun 19, 2009 at 10:54:53PM +0530, K.Prasad wrote:
> > This patch fixes two issues reported with ksym tracer, seen after
> > removal of a symbol from the tracer i) Concatenation of trace logs
> > into a single line ii) Machine stall seen when logs are viewed
> > using 'trace_pipe'.
> >
> > Known issue: Upon removal, 'cat trace_pipe' (without any preceding
> > command and any further output in the trace buffer) responds to
> > SIGTERM quickly but only after an indeterminate amount of delay
> > for SIGINT.
> >
> > Signed-off-by: K.Prasad <[email protected]>
> > ---
> > kernel/trace/trace.h | 12 +++++++++---
> > kernel/trace/trace_ksym.c | 11 ++++-------
> > 2 files changed, 13 insertions(+), 10 deletions(-)
> >
> > Index: linux-2.6-tip.hbkpt/kernel/trace/trace_ksym.c
> > ===================================================================
> > --- linux-2.6-tip.hbkpt.orig/kernel/trace/trace_ksym.c
> > +++ linux-2.6-tip.hbkpt/kernel/trace/trace_ksym.c
> > @@ -71,7 +71,7 @@ void ksym_hbp_handler(struct hw_breakpoi
> > {
> > struct ring_buffer_event *event;
> > struct trace_array *tr;
> > - struct trace_ksym *entry;
> > + struct trace_ksym_rb *entry;
> > int pc;
> >
> > if (!ksym_tracing_enabled)
> > @@ -87,7 +87,7 @@ void ksym_hbp_handler(struct hw_breakpoi
> >
> > entry = ring_buffer_event_data(event);
> > strlcpy(entry->ksym_name, hbp->info.name, KSYM_SYMBOL_LEN);
> > - entry->ksym_hbp = hbp;
> > + memcpy(&(entry->ksym_hbp), hbp, sizeof(struct hw_breakpoint));
>
>
> That looks wasteful. You only need the type from the arch_hw_breakpoint
> and there you copy the whole generic breakpoint.
>
> Frederic.
>
Well, the entire copy operation for ksym_name and p_name is indeed a
much bigger waste (KSYM_SYMBOL_LEN and TASK_COMM_LEN bytes respetively)
and the breakpoint structure size is tiny in comparison.
The type information is an arch-specific field and it encapsulated
within 'struct hw_breakpoint'. In any case this solution needs
improvement more in terms of getting the tracer infrastructure to
identify stale entries (belonging to removed symbols) and prevent their
display. The existing trace logs contain huge redundant information due
to multiple copies of the same data and it would yield much better results
than such trivial optimisations. The ksym_tracer, I believe, has just
unearthed the opportunity for the same as it is (is it?) the first such
ftrace plugin to partially remove entries.
Thanks,
K.Prasad
On Sat, Jun 20, 2009 at 09:27:25AM +0530, K.Prasad wrote:
> On Sat, Jun 20, 2009 at 01:03:49AM +0200, Frederic Weisbecker wrote:
> > On Fri, Jun 19, 2009 at 10:54:53PM +0530, K.Prasad wrote:
> > > This patch fixes two issues reported with ksym tracer, seen after
> > > removal of a symbol from the tracer i) Concatenation of trace logs
> > > into a single line ii) Machine stall seen when logs are viewed
> > > using 'trace_pipe'.
> > >
> > > Known issue: Upon removal, 'cat trace_pipe' (without any preceding
> > > command and any further output in the trace buffer) responds to
> > > SIGTERM quickly but only after an indeterminate amount of delay
> > > for SIGINT.
> > >
> > > Signed-off-by: K.Prasad <[email protected]>
> > > ---
> > > kernel/trace/trace.h | 12 +++++++++---
> > > kernel/trace/trace_ksym.c | 11 ++++-------
> > > 2 files changed, 13 insertions(+), 10 deletions(-)
> > >
> > > Index: linux-2.6-tip.hbkpt/kernel/trace/trace_ksym.c
> > > ===================================================================
> > > --- linux-2.6-tip.hbkpt.orig/kernel/trace/trace_ksym.c
> > > +++ linux-2.6-tip.hbkpt/kernel/trace/trace_ksym.c
> > > @@ -71,7 +71,7 @@ void ksym_hbp_handler(struct hw_breakpoi
> > > {
> > > struct ring_buffer_event *event;
> > > struct trace_array *tr;
> > > - struct trace_ksym *entry;
> > > + struct trace_ksym_rb *entry;
> > > int pc;
> > >
> > > if (!ksym_tracing_enabled)
> > > @@ -87,7 +87,7 @@ void ksym_hbp_handler(struct hw_breakpoi
> > >
> > > entry = ring_buffer_event_data(event);
> > > strlcpy(entry->ksym_name, hbp->info.name, KSYM_SYMBOL_LEN);
> > > - entry->ksym_hbp = hbp;
> > > + memcpy(&(entry->ksym_hbp), hbp, sizeof(struct hw_breakpoint));
> >
> >
> > That looks wasteful. You only need the type from the arch_hw_breakpoint
> > and there you copy the whole generic breakpoint.
> >
> > Frederic.
> >
>
> Well, the entire copy operation for ksym_name and p_name is indeed a
> much bigger waste (KSYM_SYMBOL_LEN and TASK_COMM_LEN bytes respetively)
> and the breakpoint structure size is tiny in comparison.
>
> The type information is an arch-specific field and it encapsulated
> within 'struct hw_breakpoint'. In any case this solution needs
> improvement more in terms of getting the tracer infrastructure to
> identify stale entries (belonging to removed symbols) and prevent their
> display. The existing trace logs contain huge redundant information due
> to multiple copies of the same data and it would yield much better results
> than such trivial optimisations. The ksym_tracer, I believe, has just
> unearthed the opportunity for the same as it is (is it?) the first such
> ftrace plugin to partially remove entries.
Well, we had such issue by the past and the problem can't
be easily solvable. Traces can possibily stay in the ring buffer for a while
until they become consumed by a reader.
It's safe and keep the things simple to just copy the required informations
in the ring buffer.
Also your type is indeed arch dependent, but copying struct hw_breakpoint
instead of the hw_breakpoint in the ring buffer doesn't solve the problem,
you'll still have some #ifdef ARCH once you'll need to support other archs.
Copying the whole struct breakpoint in the ring buffer doesn't make sense.
You're even copying the address of the triggered callback whereas all you
need is only the type field from the struct arch_hw_breakpoint ?
Btw, that makes me remind that I really think this hardware breakpoint API
should provide a real abstraction of the arch dependent hardware breakpoints.
>
> Thanks,
> K.Prasad
>