Re: [PATCH 3/5] logger: Log to the FTrace buffer if tracing is enabled

[Laurent Pinchart <laurent.pinchart@ideasonboard.com>]

Hi Kieran,

On Friday 25 Nov 2016 18:10:10 Kieran Bingham wrote:
> On 25/11/16 17:40, Laurent Pinchart wrote:
> > On Friday 25 Nov 2016 13:59:14 Kieran Bingham wrote:
> >> From: Kieran Bingham <kieran@bingham.xyz>
> >> 
> >> Extend the logger such that it will detect the tracing system, and also
> >> append print statement to this ring buffer.
> >> 
> >> This provides the relevant logging output interspersed in the ftrace
> >> logs for an effective solution to identifying the actions that caused
> >> the traces to occur
> >> 
> >> Signed-off-by: Kieran Bingham <kieran@bingham.xyz>
> >> ---
> >> 
> >>  scripts/logger.sh | 13 ++++++++++++-
> >>  1 file changed, 12 insertions(+), 1 deletion(-)
> >> 
> >> diff --git a/scripts/logger.sh b/scripts/logger.sh
> >> index 8123f0c9f6e3..8412b0ba9a08 100755
> >> --- a/scripts/logger.sh
> >> +++ b/scripts/logger.sh
> >> @@ -6,6 +6,17 @@ now() {
> >> 
> >>  label=${1:+ [$1]}
> >> 
> >> +TRACE_MARKER=/sys/kernel/debug/tracing/trace_marker
> >> +if [ -e $TRACE_MARKER ]; then
> >> +	extra_log_files=$TRACE_MARKER
> >> +fi
> >> +
> >> 
> >>  while read line ; do
> >> 
> >> -	echo "$(now)$label $line"
> >> +	newline="$(now)$label $line"
> >> +
> >> +	echo "$newline"
> >> +
> >> +	for f in $extra_log_files; do
> >> +		echo "$newline" >> $f;
> > 
> > As the tracer adds a timestamp, should you echo "$label $line" only here ?
> 
> Hrm, yes it is possibly a little bit redundant...
> 
> My only argument would be that it will be a 'different' timestamp to the
> one logged by logger.sh.
> 
> Inspection of a recent log shows a difference of around 40-50 ms, which
> will be the latency between capturing the time in $(now) and passing the
> buffer to the kernel.
> 
> At this level though, the logger.sh is already susceptible to scheduler
> jitter anyway, so I'm not too worried about 40 ms. But anyone reading
> the logs will have to be aware of that extra latency.

If you think we should keep the timestamp I'm fine with that.

> >> +	done;
> >> 
> >>  done

-- 
Regards,

Laurent Pinchart