From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751272AbdCPDWZ (ORCPT ); Wed, 15 Mar 2017 23:22:25 -0400 Received: from mail.kernel.org ([198.145.29.136]:35958 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750858AbdCPDWY (ORCPT ); Wed, 15 Mar 2017 23:22:24 -0400 Date: Wed, 15 Mar 2017 23:20:30 -0400 From: Steven Rostedt To: Andi Kleen Cc: akpm@linux-foundation.org, linux-kernel@vger.kernel.org, Andi Kleen Subject: Re: [PATCH 1/7] trace: Move trace_seq_overflowed out of line Message-ID: <20170315232030.19d9ffe2@gandalf.local.home> In-Reply-To: <20170316022756.GF14380@two.firstfloor.org> References: <20170315021431.13107-1-andi@firstfloor.org> <20170315021431.13107-2-andi@firstfloor.org> <20170315205420.53b5e105@grimm.local.home> <20170316022756.GF14380@two.firstfloor.org> X-Mailer: Claws Mail 3.14.0 (GTK+ 2.24.31; x86_64-pc-linux-gnu) MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Wed, 15 Mar 2017 19:27:57 -0700 Andi Kleen wrote: > On Wed, Mar 15, 2017 at 08:54:20PM -0400, Steven Rostedt wrote: > > On Tue, 14 Mar 2017 19:14:25 -0700 > > Andi Kleen wrote: > > > > > From: Andi Kleen > > > > > > Inlining trace_seq_overflowed takes ~17k in text size in my kernel. > > > The function doesn't seem to be time critical, so we can just out of line it. > > > > Instead of out of lining trace_seq_has_overflowed(), have you tried to > > out of line the function that's called by tracepoints (one per > > tracepoint). That is, trace_handle_return()? > > This is a data driven approach so I always went for the largest savings. > > > > > The trace_seq_handle_overflow() is used in not reproduced places that I > > would like to keep it as an inline. If the issue is size of the kernel, > > I cannot parse this sentence. What advantage has it being inline? Because you don't understand the problem. And why I'm against your patch! > > > please just out of line the one place that calls it that is duplicated > > for every tracepoint. Which happens to be trace_handle_return(). > > It is used in lots of places outside trace_handle_return, so that would > give far less savings. Have you actually looked at what trace_seq_has_overflowed() is? static inline bool trace_seq_has_overflowed(struct trace_seq *s) { return s->full || seq_buf_has_overflowed(&s->seq); } static inline bool seq_buf_has_overflowed(struct seq_buf *s) { return s->len > s->size; } Basically trace_seq_has_overflowed() is the same as: return s->full || s->seq->len > s->seq->size You really think the above in 24 locations would cause 17k difference?? > > -Andi > > include/linux/trace_events.h:143: return trace_seq_has_overflowed(s) ? Every thing below is negligible. The above which is called in trace_handle_return() is your problem. Let me explain it to you. The above is part of the TRACE_EVENT() logic. It is duplicated for *every* tracepoint in the system. Looking at a current kernel: # ls /debug/tracing/events/*/*/enable | wc -l 1267 There's 1267 events. That means the function trace_handle_return() is called 1267 times! THAT IS THE PROBLEM!!!! Look at include/trace/trace_events.h for trace_raw_output_##call() That's the macro that creates over a thousand functions calling trace_handle_return(). So please, fix where the issue is and not the other function, as 23 callers is not going to be noticed. -- Steve > include/linux/trace_seq.h:60: * trace_seq_has_overflowed - return true if the trace_seq took too much > include/linux/trace_seq.h:66:static inline bool trace_seq_has_overflowed(struct trace_seq *s) > kernel/trace/ring_buffer.c:47: return !trace_seq_has_overflowed(s); > kernel/trace/ring_buffer.c:390: return !trace_seq_has_overflowed(s); > kernel/trace/trace.c:3268: if (trace_seq_has_overflowed(s)) > kernel/trace/trace.c:3292: if (trace_seq_has_overflowed(s)) > kernel/trace/trace.c:3318: if (trace_seq_has_overflowed(s)) > kernel/trace/trace.c:3347: if (trace_seq_has_overflowed(s)) > kernel/trace/trace.c:3399: if (trace_seq_has_overflowed(&iter->seq)) > kernel/trace/trace.c:5490: if (trace_seq_has_overflowed(&iter->seq)) { > kernel/trace/trace_functions_graph.c:910: if (trace_seq_has_overflowed(s)) > kernel/trace/trace_functions_graph.c:1221: if (trace_seq_has_overflowed(s)) > kernel/trace/trace_output.c:354: return !trace_seq_has_overflowed(s); > kernel/trace/trace_output.c:374: return !trace_seq_has_overflowed(s); > kernel/trace/trace_output.c:435: return !trace_seq_has_overflowed(s); > kernel/trace/trace_output.c:522: return !trace_seq_has_overflowed(s); > kernel/trace/trace_output.c:550: return !trace_seq_has_overflowed(s); > kernel/trace/trace_output.c:586: return !trace_seq_has_overflowed(s); > kernel/trace/trace_output.c:1021: if (trace_seq_has_overflowed(s)) > kernel/trace/trace_output.c:1071: if (ip == ULONG_MAX || trace_seq_has_overflowed(s)) > kernel/trace/trace_probe.c:44: return !trace_seq_has_overflowed(s); \ > kernel/trace/trace_probe.c:73: return !trace_seq_has_overflowed(s); > kernel/trace/trace_syscalls.c:147: if (trace_seq_has_overflowed(s)) >