Re: [PATCH 16/37] perf tools: Add a test case for timed thread handling

[Jiri Olsa <jolsa@redhat.com>]

On Wed, Dec 24, 2014 at 04:15:12PM +0900, Namhyung Kim wrote:

SNIP

>  		.func = NULL,
>  	},
>  };
> diff --git a/tools/perf/tests/tests.h b/tools/perf/tests/tests.h
> index 43ac17780629..1090337f63e5 100644
> --- a/tools/perf/tests/tests.h
> +++ b/tools/perf/tests/tests.h
> @@ -52,6 +52,7 @@ int test__switch_tracking(void);
>  int test__fdarray__filter(void);
>  int test__fdarray__add(void);
>  int test__thread_comm(void);
> +int test__thread_lookup_time(void);
>  
>  #if defined(__x86_64__) || defined(__i386__) || defined(__arm__)
>  #ifdef HAVE_DWARF_UNWIND_SUPPORT
> diff --git a/tools/perf/tests/thread-lookup-time.c b/tools/perf/tests/thread-lookup-time.c
> new file mode 100644
> index 000000000000..6237ecf8caae
> --- /dev/null
> +++ b/tools/perf/tests/thread-lookup-time.c
> @@ -0,0 +1,174 @@
> +#include "tests.h"
> +#include "machine.h"
> +#include "thread.h"
> +#include "map.h"
> +#include "debug.h"
> +
> +static int thread__print_cb(struct thread *th, void *arg __maybe_unused)
> +{
> +	printf("thread: %d, start time: %"PRIu64" %s\n",
> +	       th->tid, th->start_time, th->dead ? "(dead)" : "");
> +	return 0;
> +}
> +
> +static int lookup_with_timestamp(struct machine *machine)
> +{
> +	struct thread *t1, *t2, *t3;
> +	union perf_event fork = {
> +		.fork = {
> +			.pid = 0,
> +			.tid = 0,
> +			.ppid = 1,
> +			.ptid = 1,
> +		},

I've got following output from the test:

test child forked, pid 18483
========= after t1 created ==========
thread: 0, start time: 0 
========= after t1 set comm ==========
thread: 0, start time: 20000 
========= after t2 forked ==========
thread: 0, start time: 50000 
thread: 1, start time: 0 
thread: 0, start time: 10000 
thread: 0, start time: 20000 (dead)
========= after t3 forked ==========
thread: 0, start time: 60000 
thread: 1, start time: 0 
thread: 0, start time: 10000 
thread: 0, start time: 50000 (dead)
thread: 0, start time: 20000 (dead)
test child finished with 0

'after t2 forked' data shows 'thread 0 with time 50000' and
newly added parent 'thread: 1, start time: 0'

this makes me wonder if you wanted switch 0 and 1 for pid and ppid
in above sample init and follow with forked pid 1 ... but not sure
because you're using the same sample for fork 3 ;-)

my question is if that was intentional, because I've got
confused in here

> +	};
> +	struct perf_sample sample = {
> +		.time = 50000,
> +	};
> +
> +	/* start_time is set to 0 */
> +	t1 = machine__findnew_thread(machine, 0, 0);
> +
> +	if (verbose > 1) {
> +		printf("========= after t1 created ==========\n");
> +		machine__for_each_thread(machine, thread__print_cb, NULL);
> +	}
> +
> +	TEST_ASSERT_VAL("wrong start time of old thread", t1->start_time == 0);
> +
> +	TEST_ASSERT_VAL("cannot find current thread",
> +			machine__find_thread(machine, 0, 0) == t1);
> +
> +	TEST_ASSERT_VAL("cannot find current thread with time",
> +			machine__findnew_thread_time(machine, 0, 0, 10000) == t1);
> +
> +	/* start_time is overwritten to new value */
> +	thread__set_comm(t1, "/usr/bin/perf", 20000);
> +
> +	if (verbose > 1) {
> +		printf("========= after t1 set comm ==========\n");
> +		machine__for_each_thread(machine, thread__print_cb, NULL);
> +	}
> +
> +	TEST_ASSERT_VAL("failed to update start time", t1->start_time == 20000);
> +
> +	TEST_ASSERT_VAL("should not find passed thread",
> +			/* this will create yet another dead thread */
> +			machine__findnew_thread_time(machine, 0, 0, 10000) != t1);

also this comment say that calling machine__findnew_thread_time will
create another dead thread, which actually did not happened based on
above test output

thanks,
jirka