Re: [GIT PULL 00/42] perf/core improvements and fixes

From: Namhyung Kim <namhyung@kernel.org>
To: Ingo Molnar <mingo@kernel.org>
Cc: Arnaldo Carvalho de Melo <acme@infradead.org>,
	linux-kernel@vger.kernel.org, Arun Sharma <asharma@fb.com>,
	Corey Ashford <cjashfor@linux.vnet.ibm.com>,
	David Ahern <dsahern@gmail.com>,
	Dong Hao <haodong@linux.vnet.ibm.com>,
	Frederic Weisbecker <fweisbec@gmail.com>,
	Irina Tirdea <irina.tirdea@gmail.com>,
	Irina Tirdea <irina.tirdea@intel.com>,
	Jiri Olsa <jolsa@redhat.com>, Mike Galbraith <efault@gmx.de>,
	Paul Mackerras <paulus@samba.org>,
	Peter Zijlstra <peterz@infradead.org>,
	Runzhen Wang <runzhen@linux.vnet.ibm.com>,
	Stephane Eranian <eranian@google.com>,
	Xiao Guangrong <xiaoguangrong@linux.vnet.ibm.com>,
	arnaldo.melo@gmail.com,
	Arnaldo Carvalho de Melo <acme@redhat.com>
Subject: Re: [GIT PULL 00/42] perf/core improvements and fixes
Date: Fri, 05 Oct 2012 17:51:56 +0900	[thread overview]
Message-ID: <87d30xjo7n.fsf@sejong.aot.lge.com> (raw)
In-Reply-To: <20121005081804.GA685@gmail.com> (Ingo Molnar's message of "Fri, 5 Oct 2012 10:18:04 +0200")

Hi Ingo,

On Fri, 5 Oct 2012 10:18:04 +0200, Ingo Molnar wrote:
> I also noticed a 'perf trace' bug, after running 'perf trace' it 
> outputs lines but then gets hung:
>
>   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                               
>  6081 mingo     20   0 18.2g  14g 3544 D 18.6 91.2   0:20.28 perf                    
>
> and then after half a minute it gets active again, outputting 
> lines and then segfaulting:
>
>  LOST 1 events!
>  31082 ) = 375
>  31082 write(fd: 3, buf: 140030569454096, count: 48LOST 1 events!
>  31082 select(n: 13, inp: 140030569376688, outp: 140030569376656, exp: 0, tvp: 031082 ) = 2
>  Segmentation fault
>
> It's a 16-way box running:
>
>  Linux comet 3.5.4-1.fc17.x86_64 #1 SMP Mon Sep 17 15:03:59 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux
>
> Note how much the RSS is, 14 GB of RAM with less of 1 minute 
> running. The segfault might be related to a failed allocation 
> not being handled correctly perhaps.

I also hit the segfault but it was due to a broken sample data:

Core was generated by `./perf trace'.
Program terminated with signal 11, Segmentation fault.
#0  perf_evsel__intval (evsel=evsel@entry=0xeae8c0, sample=sample@entry=0x7fff42278130, name=name@entry=0x55034d "id")
    at util/evsel.c:1148
1148			value = *(u64 *)ptr;

(gdb) bt
#0  perf_evsel__intval (evsel=evsel@entry=0xeae8c0, sample=sample@entry=0x7fff42278130, name=name@entry=0x55034d "id")
    at util/evsel.c:1148
#1  0x0000000000446987 in trace__syscall_info (sample=0x7fff42278130, evsel=0xeae8c0, trace=0x7fff422781b0)
    at builtin-trace.c:147
#2  trace__sys_exit (trace=0x7fff422781b0, evsel=0xeae8c0, sample=0x7fff42278130) at builtin-trace.c:193
#3  0x00000000004470c1 in trace__run (argv=<optimized out>, argc=<optimized out>, trace=0x7fff422781b0) at builtin-trace.c:310
#4  cmd_trace (argc=<optimized out>, argv=<optimized out>, prefix=<optimized out>) at builtin-trace.c:396
#5  0x0000000000418c93 in run_builtin (p=p@entry=0x7b19d8, argc=argc@entry=1, argv=argv@entry=0x7fff4227a7a0) at perf.c:312
#6  0x000000000041846e in handle_internal_command (argv=0x7fff4227a7a0, argc=1) at perf.c:360
#7  run_argv (argv=0x7fff4227a590, argcp=0x7fff4227a59c) at perf.c:404
#8  main (argc=1, argv=0x7fff4227a7a0) at perf.c:502
(gdb) list
1143			break;
1144		case 4:
1145			value = *(u32 *)ptr;
1146			break;
1147		case 8:
1148			value = *(u64 *)ptr;
1149			break;
1150		default:
1151			return 0;
1152		}
(gdb) p ptr
$1 = (void *) 0x10
(gdb) p *sample
$2 = {ip = 0, pid = 0, tid = 0, time = 15762598695796738, addr = 0, id = 315, stream_id = 18446744073709551615, period = 1, 
  cpu = 143, raw_size = 0, raw_data = 0x0, callchain = 0x0, branch_stack = 0x0, user_regs = {regs = 0x0}, user_stack = {
    offset = 0, size = 0, data = 0x0}}

In this case 'sample->raw_data' was NULL and other fields seemed invalid
as well.  I guess we need some kind of protection?

Thanks,
Namhyung