perf sched timehist: Introduce --idle-hist option (v1)

index 870d94cd20ba..6991686bcaa5 100644
@@ -2583,6 +2583,7 @@ static int perf_sched__timehist(struct perf_sched *sched)
 	struct perf_data_file file = {
 		.path = input_name,
 		.mode = PERF_DATA_MODE_READ,
+		.force = sched->force,
 	};
 
 	struct perf_session *session;

@@ -2984,6 +2985,7 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
 		    "be more verbose (show symbol address, etc)"),
 	OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
 		    "dump raw trace in ASCII"),
+	OPT_BOOLEAN('f', "force", &sched.force, "don't complain, do it"),
 	OPT_END()
 	};
 	const struct option latency_options[] = {

@@ -2991,8 +2993,6 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
 		   "sort by key(s): runtime, switch, avg, max"),
 	OPT_INTEGER('C', "CPU", &sched.profile_cpu,
 		    "CPU to profile on"),
-	OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
-		    "dump raw trace in ASCII"),
 	OPT_BOOLEAN('p', "pids", &sched.skip_merge,
 		    "latency stats per pid instead of per comm"),
 	OPT_PARENT(sched_options)

@@ -3000,9 +3000,6 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
 	const struct option replay_options[] = {
 	OPT_UINTEGER('r', "repeat", &sched.replay_repeat,
 		     "repeat the workload replay N times (-1: infinite)"),
-	OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace,
-		    "dump raw trace in ASCII"),
-	OPT_BOOLEAN('f', "force", &sched.force, "don't complain, do it"),
 	OPT_PARENT(sched_options)
 	};
 	const struct option map_options[] = {

index 823befd8209a..42922512c1c6 100644
@@ -1234,3 +1234,30 @@ int callchain_node__make_parent_list(struct callchain_node *node)
 	}
 	return -ENOMEM;
 }
+
+int callchain_cursor__copy(struct callchain_cursor *dst,
+			   struct callchain_cursor *src)
+{
+	int rc = 0;
+
+	callchain_cursor_reset(dst);
+	callchain_cursor_commit(src);
+
+	while (true) {
+		struct callchain_cursor_node *node;
+
+		node = callchain_cursor_current(src);
+		if (node == NULL)
+			break;
+
+		rc = callchain_cursor_append(dst, node->ip, node->map, node->sym,
+					     node->branch, &node->branch_flags,
+					     node->nr_loop_iter, node->samples);
+		if (rc)
+			break;
+
+		callchain_cursor_advance(src);
+	}
+
+	return rc;
+}

index d9c70dccf06a..35c8e379530f 100644
@@ -216,6 +216,9 @@ static inline void callchain_cursor_advance(struct callchain_cursor *cursor)
 	cursor->pos++;
 }
 
+int callchain_cursor__copy(struct callchain_cursor *dst,
+			   struct callchain_cursor *src);
+
 struct option;
 struct hist_entry;
 

index 6991686bcaa5..e34a71166b4a 100644
@@ -2118,7 +2118,9 @@ static struct thread *timehist_get_thread(struct perf_sched *sched,
 			pr_err("Failed to get idle thread for cpu %d.\n", sample->cpu);
 
 	} else {
-		thread = machine__findnew_thread(machine, sample->pid, sample->tid);
+		/* there were samples with tid 0 but non-zero pid */
+		thread = machine__findnew_thread(machine, sample->pid,
+						 sample->tid ?: sample->pid);
 		if (thread == NULL) {
 			pr_debug("Failed to get thread for tid %d. skipping sample.\n",
 				 sample->tid);

index e34a71166b4a..5f69c9b9c78f 100644
@@ -1939,39 +1939,36 @@ static void timehist_update_runtime_stats(struct thread_runtime *r,
 	r->total_run_time += r->dt_run;
 }
 
-static bool is_idle_sample(struct perf_sched *sched,
-			   struct perf_sample *sample,
-			   struct perf_evsel *evsel,
-			   struct machine *machine)
+static bool is_idle_sample(struct perf_sample *sample)
 {
-	struct thread *thread;
-	struct callchain_cursor *cursor = &callchain_cursor;
-
 	/* pid 0 == swapper == idle task */
-	if (sample->pid == 0)
-		return true;
+	return (sample->pid == 0);
+}
 
-	if (strcmp(perf_evsel__name(evsel), "sched:sched_switch") == 0) {
-		if (perf_evsel__intval(evsel, sample, "prev_pid") == 0)
-			return true;
-	}
+static void save_task_callchain(struct perf_sched *sched,
+				struct perf_sample *sample,
+				struct perf_evsel *evsel,
+				struct machine *machine)
+{
+	struct callchain_cursor *cursor = &callchain_cursor;
+	struct thread *thread;
 
 	/* want main thread for process - has maps */
 	thread = machine__findnew_thread(machine, sample->pid, sample->pid);
 	if (thread == NULL) {
 		pr_debug("Failed to get thread for pid %d.\n", sample->pid);
-		return false;
+		return;
 	}
 
 	if (!symbol_conf.use_callchain || sample->callchain == NULL)
-		return false;
+		return;
 
 	if (thread__resolve_callchain(thread, cursor, evsel, sample,
 				      NULL, NULL, sched->max_stack + 2) != 0) {
 		if (verbose)
 			error("Failed to resolve callchain. Skipping\n");
 
-		return false;
+		return;
 	}
 
 	callchain_cursor_commit(cursor);

@@ -1994,8 +1991,6 @@ static bool is_idle_sample(struct perf_sched *sched,
 
 		callchain_cursor_advance(cursor);
 	}
-
-	return false;
 }
 
 /*

@@ -2112,7 +2107,7 @@ static struct thread *timehist_get_thread(struct perf_sched *sched,
 {
 	struct thread *thread;
 
-	if (is_idle_sample(sched, sample, evsel, machine)) {
+	if (is_idle_sample(sample)) {
 		thread = get_idle_thread(sample->cpu);
 		if (thread == NULL)
 			pr_err("Failed to get idle thread for cpu %d.\n", sample->cpu);

@@ -2125,6 +2120,8 @@ static struct thread *timehist_get_thread(struct perf_sched *sched,
 			pr_debug("Failed to get thread for tid %d. skipping sample.\n",
 				 sample->tid);
 		}
+
+		save_task_callchain(sched, sample, evsel, machine);
 	}
 
 	return thread;

index 5f69c9b9c78f..26efa99567b8 100644
@@ -2005,7 +2005,7 @@ static int init_idle_threads(int ncpu)
 	if (!idle_threads)
 		return -ENOMEM;
 
-	idle_max_cpu = ncpu - 1;
+	idle_max_cpu = ncpu;
 
 	/* allocate the actual thread struct if needed */
 	for (i = 0; i < ncpu; ++i) {

@@ -2026,7 +2026,7 @@ static void free_idle_threads(void)
 	if (idle_threads == NULL)
 		return;
 
-	for (i = 0; i <= idle_max_cpu; ++i) {
+	for (i = 0; i < idle_max_cpu; ++i) {
 		if ((idle_threads[i]))
 			thread__delete(idle_threads[i]);
 	}

@@ -2049,8 +2049,7 @@ static struct thread *get_idle_thread(int cpu)
 			return NULL;
 
 		idle_threads = (struct thread **) p;
-		i = idle_max_cpu ? idle_max_cpu + 1 : 0;
-		for (; i < j; ++i)
+		for (i = idle_max_cpu; i < j; ++i)
 			idle_threads[i] = NULL;
 
 		idle_max_cpu = j;

@@ -2492,7 +2491,7 @@ static void timehist_print_summary(struct perf_sched *sched,
 		return;
 
 	printf("\nIdle stats:\n");
-	for (i = 0; i <= idle_max_cpu; ++i) {
+	for (i = 0; i < idle_max_cpu; ++i) {
 		t = idle_threads[i];
 		if (!t)
 			continue;

index 26efa99567b8..d3ee814ce77f 100644
@@ -230,6 +230,15 @@ struct evsel_runtime {
 	u32 ncpu;       /* highest cpu slot allocated */
 };
 
+/* per cpu idle time data */
+struct idle_thread_runtime {
+	struct thread_runtime tr;
+	struct thread *last_thread;
+	struct rb_root sorted_root;
+	struct callchain_root callchain;
+	struct callchain_cursor cursor;
+};
+
 /* track idle times per cpu */
 static struct thread **idle_threads;
 static int idle_max_cpu;

@@ -2009,11 +2018,22 @@ static int init_idle_threads(int ncpu)
 
 	/* allocate the actual thread struct if needed */
 	for (i = 0; i < ncpu; ++i) {
+		struct idle_thread_runtime *itr;
+
 		idle_threads[i] = thread__new(0, 0);
 		if (idle_threads[i] == NULL)
 			return -ENOMEM;
 
 		thread__set_comm(idle_threads[i], idle_comm, 0);
+
+		itr = zalloc(sizeof(*itr));
+		if (itr == NULL)
+			return -ENOMEM;
+
+		init_stats(&itr->tr.run_stats);
+		callchain_init(&itr->callchain);
+		callchain_cursor_reset(&itr->cursor);
+		thread__set_priv(idle_threads[i], itr);
 	}
 
 	return 0;

@@ -2060,8 +2080,19 @@ static struct thread *get_idle_thread(int cpu)
 		idle_threads[cpu] = thread__new(0, 0);
 
 		if (idle_threads[cpu]) {
+			struct idle_thread_runtime *itr;
+
 			idle_threads[cpu]->tid = 0;
 			thread__set_comm(idle_threads[cpu], idle_comm, 0);
+
+			itr = zalloc(sizeof(*itr));
+			if (itr == NULL)
+				return NULL;
+
+			init_stats(&itr->tr.run_stats);
+			callchain_init(&itr->callchain);
+			callchain_cursor_reset(&itr->cursor);
+			thread__set_priv(idle_threads[cpu], itr);
 		}
 	}
 

index d3ee814ce77f..058cb549cf3e 100644
@@ -200,6 +200,7 @@ struct perf_sched {
 	/* options for timehist command */
 	bool		summary;
 	bool		summary_only;
+	bool		idle_hist;
 	bool		show_callchain;
 	unsigned int	max_stack;
 	bool		show_cpu_visual;

@@ -2099,6 +2100,29 @@ static struct thread *get_idle_thread(int cpu)
 	return idle_threads[cpu];
 }
 
+static void save_idle_callchain(struct thread *thread,
+				struct perf_sample *sample)
+{
+	struct thread *idle;
+	struct idle_thread_runtime *itr;
+
+	if (!symbol_conf.use_callchain || sample->callchain == NULL)
+		return;
+
+	idle = get_idle_thread(sample->cpu);
+	if (idle == NULL) {
+		pr_err("Failed to get idle thread for cpu %d.\n", sample->cpu);
+		return;
+	}
+
+	itr = thread__priv(idle);
+	if (itr == NULL)
+		return;
+
+	itr->last_thread = thread;
+	callchain_cursor__copy(&itr->cursor, &callchain_cursor);
+}
+
 /*
  * handle runtime stats saved per thread
  */

@@ -2152,6 +2176,11 @@ static struct thread *timehist_get_thread(struct perf_sched *sched,
 		}
 
 		save_task_callchain(sched, sample, evsel, machine);
+		if (sched->idle_hist) {
+			/* copy task callchain when entering to idle */
+			if (perf_evsel__intval(evsel, sample, "next_pid") == 0)
+				save_idle_callchain(thread, sample);
+		}
 	}
 
 	return thread;

index 058cb549cf3e..8df562ff3a43 100644
@@ -2187,7 +2187,9 @@ static struct thread *timehist_get_thread(struct perf_sched *sched,
 }
 
 static bool timehist_skip_sample(struct perf_sched *sched,
-				 struct thread *thread)
+				 struct thread *thread,
+				 struct perf_evsel *evsel,
+				 struct perf_sample *sample)
 {
 	bool rc = false;
 

@@ -2196,10 +2198,19 @@ static bool timehist_skip_sample(struct perf_sched *sched,
 		sched->skipped_samples++;
 	}
 
+	if (sched->idle_hist) {
+		if (strcmp(perf_evsel__name(evsel), "sched:sched_switch"))
+			rc = true;
+		else if (perf_evsel__intval(evsel, sample, "prev_pid") != 0 &&
+			 perf_evsel__intval(evsel, sample, "next_pid") != 0)
+			rc = true;
+	}
+
 	return rc;
 }
 
 static void timehist_print_wakeup_event(struct perf_sched *sched,
+					struct perf_evsel *evsel,
 					struct perf_sample *sample,
 					struct machine *machine,
 					struct thread *awakened)

@@ -2212,8 +2223,8 @@ static void timehist_print_wakeup_event(struct perf_sched *sched,
 		return;
 
 	/* show wakeup unless both awakee and awaker are filtered */
-	if (timehist_skip_sample(sched, thread) &&
-	    timehist_skip_sample(sched, awakened)) {
+	if (timehist_skip_sample(sched, thread, evsel, sample) &&
+	    timehist_skip_sample(sched, awakened, evsel, sample)) {
 		return;
 	}
 

@@ -2258,7 +2269,7 @@ static int timehist_sched_wakeup_event(struct perf_tool *tool,
 	/* show wakeups if requested */
 	if (sched->show_wakeups &&
 	    !perf_time__skip_sample(&sched->ptime, sample->time))
-		timehist_print_wakeup_event(sched, sample, machine, thread);
+		timehist_print_wakeup_event(sched, evsel, sample, machine, thread);
 
 	return 0;
 }

@@ -2285,8 +2296,8 @@ static void timehist_print_migration_event(struct perf_sched *sched,
 	if (thread == NULL)
 		return;
 
-	if (timehist_skip_sample(sched, thread) &&
-	    timehist_skip_sample(sched, migrated)) {
+	if (timehist_skip_sample(sched, thread, evsel, sample) &&
+	    timehist_skip_sample(sched, migrated, evsel, sample)) {
 		return;
 	}
 

@@ -2371,7 +2382,7 @@ static int timehist_sched_change_event(struct perf_tool *tool,
 		goto out;
 	}
 
-	if (timehist_skip_sample(sched, thread))
+	if (timehist_skip_sample(sched, thread, evsel, sample))
 		goto out;
 
 	tr = thread__get_runtime(thread);

index 8df562ff3a43..7a5a497d9fa2 100644
@@ -2418,7 +2418,28 @@ static int timehist_sched_change_event(struct perf_tool *tool,
 			t = ptime->end;
 	}
 
-	timehist_update_runtime_stats(tr, t, tprev);
+	if (!sched->idle_hist || thread->tid == 0) {
+		timehist_update_runtime_stats(tr, t, tprev);
+
+		if (sched->idle_hist) {
+			struct idle_thread_runtime *itr = (void *)tr;
+			struct thread_runtime *last_tr;
+
+			BUG_ON(thread->tid != 0);
+
+			if (itr->last_thread == NULL)
+				goto out;
+
+			/* add current idle time as last thread's runtime */
+			last_tr = thread__get_runtime(itr->last_thread);
+			if (last_tr == NULL)
+				goto out;
+
+			timehist_update_runtime_stats(last_tr, t, tprev);
+
+			itr->last_thread = NULL;
+		}
+	}
 
 	if (!sched->summary_only)
 		timehist_print_sample(sched, sample, &al, thread, t);

@@ -2540,9 +2561,15 @@ static void timehist_print_summary(struct perf_sched *sched,
 	if (comm_width < 30)
 		comm_width = 30;
 
-	printf("\nRuntime summary\n");
-	printf("%*s  parent   sched-in  ", comm_width, "comm");
-	printf("   run-time    min-run     avg-run     max-run  stddev  migrations\n");
+	if (sched->idle_hist) {
+		printf("\nIdle-time summary\n");
+		printf("%*s  parent  sched-out  ", comm_width, "comm");
+		printf("  idle-time   min-idle    avg-idle    max-idle  stddev  migrations\n");
+	} else {
+		printf("\nRuntime summary\n");
+		printf("%*s  parent   sched-in  ", comm_width, "comm");
+		printf("   run-time    min-run     avg-run     max-run  stddev  migrations\n");
+	}
 	printf("%*s            (count)  ", comm_width, "");
 	printf("     (msec)     (msec)      (msec)      (msec)       %%\n");
 	printf("%.117s\n", graph_dotted_line);

@@ -2558,7 +2585,7 @@ static void timehist_print_summary(struct perf_sched *sched,
 		printf("<no terminated tasks>\n");
 
 	/* CPU idle stats not tracked when samples were skipped */
-	if (sched->skipped_samples)
+	if (sched->skipped_samples && !sched->idle_hist)
 		return;
 
 	printf("\nIdle stats:\n");

@@ -3100,6 +3127,7 @@ int cmd_sched(int argc, const char **argv, const char *prefix __maybe_unused)
 	OPT_BOOLEAN('w', "wakeups", &sched.show_wakeups, "Show wakeup events"),
 	OPT_BOOLEAN('M', "migrations", &sched.show_migrations, "Show migration events"),
 	OPT_BOOLEAN('V', "cpu-visual", &sched.show_cpu_visual, "Add CPU visual"),
+	OPT_BOOLEAN('I', "idle-hist", &sched.idle_hist, "Show idle events only"),
 	OPT_STRING(0, "time", &sched.time_str, "str",
 		   "Time span for analysis (start,stop)"),
 	OPT_PARENT(sched_options)

index 7a5a497d9fa2..acd8ed5af438 100644
@@ -2436,6 +2436,9 @@ static int timehist_sched_change_event(struct perf_tool *tool,
 				goto out;
 
 			timehist_update_runtime_stats(last_tr, t, tprev);
+			if (itr->cursor.nr)
+				callchain_append(&itr->callchain, &itr->cursor,
+						 t - tprev);
 
 			itr->last_thread = NULL;
 		}

@@ -2546,6 +2549,60 @@ static int show_deadthread_runtime(struct thread *t, void *priv)
 	return __show_thread_runtime(t, priv);
 }
 
+static size_t callchain__fprintf_folded(FILE *fp, struct callchain_node *node)
+{
+	const char *sep = " <- ";
+	struct callchain_list *chain;
+	size_t ret = 0;
+	char bf[1024];
+	bool first;
+
+	if (node == NULL)
+		return 0;
+
+	ret = callchain__fprintf_folded(fp, node->parent);
+	first = (ret == 0);
+
+	list_for_each_entry(chain, &node->val, list) {
+		if (chain->ip >= PERF_CONTEXT_MAX)
+			continue;
+		if (chain->ms.sym && chain->ms.sym->ignore)
+			continue;
+		ret += fprintf(fp, "%s%s", first ? "" : sep,
+			       callchain_list__sym_name(chain, bf, sizeof(bf),
+							false));
+		first = false;
+	}
+
+	return ret;
+}
+
+static size_t timehist_print_idlehist_callchain(struct rb_root *root)
+{
+	size_t ret = 0;
+	FILE *fp = stdout;
+	struct callchain_node *chain;
+	struct rb_node *rb_node = rb_first(root);
+
+	printf("  %16s  %8s  %s\n", "Idle time (msec)", "Count", "Callchains");
+	printf("  %.16s  %.8s  %.50s\n", graph_dotted_line, graph_dotted_line,
+	       graph_dotted_line);
+
+	while (rb_node) {
+		chain = rb_entry(rb_node, struct callchain_node, rb_node);
+		rb_node = rb_next(rb_node);
+
+		ret += fprintf(fp, "  ");
+		print_sched_time(chain->hit, 12);
+		ret += 16;  /* print_sched_time returns 2nd arg + 4 */
+		ret += fprintf(fp, " %8d  ", chain->count);
+		ret += callchain__fprintf_folded(fp, chain);
+		ret += fprintf(fp, "\n");
+	}
+
+	return ret;
+}
+
 static void timehist_print_summary(struct perf_sched *sched,
 				   struct perf_session *session)
 {

@@ -2604,6 +2661,35 @@ static void timehist_print_summary(struct perf_sched *sched,
 			printf("    CPU %2d idle entire time window\n", i);
 	}
 
+	if (sched->idle_hist && symbol_conf.use_callchain) {
+		callchain_param.mode  = CHAIN_FOLDED;
+		callchain_param.value = CCVAL_PERIOD;
+
+		callchain_register_param(&callchain_param);
+
+		printf("\nIdle stats by callchain:\n");
+		for (i = 0; i < idle_max_cpu; ++i) {
+			struct idle_thread_runtime *itr;
+
+			t = idle_threads[i];
+			if (!t)
+				continue;
+
+			itr = thread__priv(t);
+			if (itr == NULL)
+				continue;
+
+			callchain_param.sort(&itr->sorted_root, &itr->callchain,
+					     0, &callchain_param);
+
+			printf("  CPU %2d:", i);
+			print_sched_time(itr->tr.total_run_time, 6);
+			printf(" msec\n");
+			timehist_print_idlehist_callchain(&itr->sorted_root);
+			printf("\n");
+		}
+	}
+
 	printf("\n"
 	       "    Total number of unique tasks: %" PRIu64 "\n"
 	       "Total number of context switches: %" PRIu64 "\n"