[PATCH] trace-cmd: Do not free pages from the lookup table in struct cpu_data in case trace file is loaded.

[PATCH] trace-cmd: Do not free pages from the lookup table in struct cpu_data in case trace file is loaded.

[tz.stoyanov]

From: "Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com>

A major speed regression in trace-cmd v2.8 is reported by Johannes Berg
when parsing a huge trace.dat file:

"I have a ~1.7G file with just under 620k events (not exactly big by our standards),
and parsing speed (with -N to disable plugins) goes from ~4.5 seconds on commit
1ad32c24746 to >>4.5 minutes (I aborted there) on master.
I was talking to Steven about another issue, and he pointed me to
commit c2fc2bc296f7. Reverting that on master makes it take ~2 seconds,
so that'd actually be an improvement."

Proposed solution: do not free pages from "struct page **pages" lookup table
in struct cpu_data, in case a trace file is loaded. This reverts the behavior
for this use case, as it was before commit c2fc2bc296f7.

Bugzilla: https://bugzilla.kernel.org/show_bug.cgi?id=203411
Fixes: c2fc2bc296f7 ("trace-cmd: Fix crash when trace-cmd is executed with args profile -F sleep 1")

Reported-by: Johannes Berg <johannes@sipsolutions.net>
Signed-off-by: Tzvetomir Stoyanov (VMware) <tz.stoyanov@gmail.com>
---
 lib/trace-cmd/trace-input.c | 20 +++++++++++---------
 1 file changed, 11 insertions(+), 9 deletions(-)

diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c
index 7acecf3..32af20c 100644
--- a/lib/trace-cmd/trace-input.c
+++ b/lib/trace-cmd/trace-input.c
@@ -987,15 +987,17 @@ static void __free_page(struct tracecmd_input *handle, struct page *page)
 
 	free(page);
 
-	for (index = cpu_data->nr_pages - 1; index > 0; index--)
-		if (cpu_data->pages[index])
-			break;
-	if (index < (cpu_data->nr_pages - 1)) {
-		pages = realloc(cpu_data->pages, (index + 1) * sizeof(*cpu_data->pages));
-		if (!pages)
-			return;
-		cpu_data->pages = pages;
-		cpu_data->nr_pages = index + 1;
+	if (handle->use_pipe) {
+		for (index = cpu_data->nr_pages - 1; index > 0; index--)
+			if (cpu_data->pages[index])
+				break;
+		if (index < (cpu_data->nr_pages - 1)) {
+			pages = realloc(cpu_data->pages, (index + 1) * sizeof(*cpu_data->pages));
+			if (!pages)
+				return;
+			cpu_data->pages = pages;
+			cpu_data->nr_pages = index + 1;
+		}
 	}
 }
 
-- 
2.21.0

Re: [PATCH] trace-cmd: Do not free pages from the lookup table in struct cpu_data in case trace file is loaded.

[Johannes Berg]

On Wed, 2019-06-19 at 14:49 +0300, tz.stoyanov@gmail.com wrote:
> From: "Tzvetomir Stoyanov (VMware)" <tz.stoyanov@gmail.com>
> 
> A major speed regression in trace-cmd v2.8 is reported by Johannes Berg
> when parsing a huge trace.dat file:
> 
> "I have a ~1.7G file with just under 620k events (not exactly big by our standards),
> and parsing speed (with -N to disable plugins) goes from ~4.5 seconds on commit
> 1ad32c24746 to >>4.5 minutes (I aborted there) on master.
> I was talking to Steven about another issue, and he pointed me to
> commit c2fc2bc296f7. Reverting that on master makes it take ~2 seconds,
> so that'd actually be an improvement."
> 
> Proposed solution: do not free pages from "struct page **pages" lookup table
> in struct cpu_data, in case a trace file is loaded. This reverts the behavior
> for this use case, as it was before commit c2fc2bc296f7.

Seems to work, more or less. I now see ~6.5 seconds which is slower than
it was, and in particular comparing to just a revert (which was ~2
seconds), but it's usable :-)

johannes

Re: [PATCH] trace-cmd: Do not free pages from the lookup table in struct cpu_data in case trace file is loaded.

[Steven Rostedt]

On Wed, 19 Jun 2019 13:52:14 +0200
Johannes Berg <johannes@sipsolutions.net> wrote:

> Seems to work, more or less. I now see ~6.5 seconds which is slower than
> it was, and in particular comparing to just a revert (which was ~2
> seconds), but it's usable :-)

I'm totally confused. Unless it is a cache miss thing, the only thing
it did was add two branches that should basically follow the old path
with the revert.

Can you run perf comparing this patch against the revert and see where
the difference lies?

Thanks!

-- Steve

Re: [PATCH] trace-cmd: Do not free pages from the lookup table in struct cpu_data in case trace file is loaded.

[Johannes Berg]

On Tue, 2019-06-25 at 18:32 -0400, Steven Rostedt wrote:
> On Wed, 19 Jun 2019 13:52:14 +0200
> Johannes Berg <johannes@sipsolutions.net> wrote:
> 
> > Seems to work, more or less. I now see ~6.5 seconds which is slower than
> > it was, and in particular comparing to just a revert (which was ~2
> > seconds), but it's usable :-)
> 
> I'm totally confused. Unless it is a cache miss thing, the only thing
> it did was add two branches that should basically follow the old path
> with the revert.
> 
> Can you run perf comparing this patch against the revert and see where
> the difference lies?

I tried, but it looks the same. Then I tried to reproduce and now I see
it also fairly consistently just under 2 seconds with the patch, so
perhaps CPU scaling or something was throwing me a curve ball before.

Sorry for the noise, patch works great.

Tested-by: Johannes Berg <johannes@sipsolutions.net>

johannes