Re: [Patch 1/2] ksym_tracer:Fix line-wrapping after removal of ksym tracer entry

["K.Prasad" <prasad@linux.vnet.ibm.com>]

On Wed, Jun 17, 2009 at 07:06:07AM +0200, Frederic Weisbecker wrote:
> On Wed, Jun 17, 2009 at 04:35:04AM +0530, K.Prasad wrote:
> > Removal of a ksym entry results in missing information and an early return with
> > TRACE_TYPE_PARTIAL_LINE code (minus the line return). This patch modifies the
> > output function to unconditionally add a line return irrespective of the
> > return code. 
> > 
> > Signed-off-by: K.Prasad <prasad@linux.vnet.ibm.com>
> > ---
> >  kernel/trace/trace_ksym.c |   27 +++++++++++++++------------
> >  1 file changed, 15 insertions(+), 12 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
> > @@ -391,29 +391,32 @@ static enum print_line_t ksym_trace_outp
> >  
> >  	ret = trace_seq_printf(s, "%-15s %-5d %-3d %-20s ", field->p_name,
> >  				entry->pid, iter->cpu, field->ksym_name);
> > -	if (!ret)
> > -		return TRACE_TYPE_PARTIAL_LINE;
> > +	if (!ret) {
> > +		ret = TRACE_TYPE_PARTIAL_LINE;
> > +		goto err_ret;
> > +	}
> >  
> > +	ret = TRACE_TYPE_PARTIAL_LINE;
> >  	switch (field->ksym_hbp->info.type) {
> >  	case HW_BREAKPOINT_WRITE:
> > -		ret = trace_seq_printf(s, " W  ");
> > +		if (!trace_seq_printf(s, " W  "))
> > +			goto err_ret;
> >  		break;
> >  	case HW_BREAKPOINT_RW:
> > -		ret = trace_seq_printf(s, " RW ");
> > +		if (!trace_seq_printf(s, " RW  "))
> > +			goto err_ret;
> >  		break;
> >  	default:
> > -		return TRACE_TYPE_PARTIAL_LINE;
> > +		goto err_ret;
> >  	}
> >  
> > -	if (!ret)
> > -		return TRACE_TYPE_PARTIAL_LINE;
> > -
> >  	sprint_symbol(str, field->ip);
> >  	ret = trace_seq_printf(s, "%-20s\n", str);
> > -	if (!ret)
> > -		return TRACE_TYPE_PARTIAL_LINE;
> > -
> > -	return TRACE_TYPE_HANDLED;
> > +	if (ret)
> > +		return TRACE_TYPE_HANDLED;
> > +err_ret:
> > +	trace_seq_printf(s, "\n");
> > +	return ret;
> 
> 
> As told in my email just before, TRACE_TYPE_PARTIAL_LINE
> won't print a truncated line or a partial line. Instead, it
> will be ignored and entirely retried later.
> Then your newline will be ignored.
> 
> ..unless we have a bug in trace.c
> 

Yes, I see that TRACE_TYPE_PARTIAL_LINE isn't the cause but the early
return that happens (without printing the \n character) because of
missing data.

> I'm not sure what it the origin of the concatenated printed entries
> Ingo has reported.
> 

The existing code in -tip reads like this:

397         switch (field->ksym_hbp->info.type) {
398         case HW_BREAKPOINT_WRITE:
399                 ret = trace_seq_printf(s, " W  ");
400                 break;
401         case HW_BREAKPOINT_RW:
402                 ret = trace_seq_printf(s, " RW ");
403                 break;
404         default:
405                 return TRACE_TYPE_PARTIAL_LINE;
406         }
407 
408         if (!ret)
409                 return TRACE_TYPE_PARTIAL_LINE;
410 
411         sprint_symbol(str, field->ip);
412         ret = trace_seq_printf(s, "%-20s\n", str);
413         if (!ret)
414                 return TRACE_TYPE_PARTIAL_LINE;
415 

Si, if the control returns early at line 405 it skips the line at 412
which prints a newline character. Line 405 is executed if
field->ksym_hbp->info.type is 0 which is true for an entry that is
removed from the filter (e.g. echo jiffies:--- > ksym_trace_filter) and
no amount of retries will help it get some new data (as it is already
free-ed).

> Did you reproduce it and then this patch fixed it?
>

Yes, it was reproduced and tested but actually it is the second patch that
helps resolve this. The "trace_seq_printf(s, "\n");" isn't required at
all.

I will re-send a new patch to you which fixes the line concatenation and
machine stall issue (after symbol removal in ksym_tracer).

Thanks,
K.Prasad