xref: /haiku/src/bin/debug/time_stats/timing_analysis.cpp (revision 44521466280be8d8f1e91bb0bdf7bd65c1375e90)
1 /*
2  * Copyright 2008-2009, Ingo Weinhold, ingo_weinhold@gmx.de.
3  * Distributed under the terms of the MIT License.
4  */
5 
6 #include <errno.h>
7 #include <stdio.h>
8 #include <stdlib.h>
9 #include <string.h>
10 #include <sys/wait.h>
11 
12 #include <algorithm>
13 
14 #include <OS.h>
15 
16 #include "time_stats.h"
17 
18 
19 #define MAX_THREADS	4096
20 
21 
22 struct UsageInfoThreadComparator {
operator ()UsageInfoThreadComparator23 	inline bool operator()(const thread_info& a, const thread_info& b)
24 	{
25 		return a.thread < b.thread;
26 	}
27 };
28 
29 
30 struct UsageInfoTimeComparator {
operator ()UsageInfoTimeComparator31 	inline bool operator()(const thread_info& a, const thread_info& b)
32 	{
33 		return a.user_time + a.kernel_time > b.user_time + b.kernel_time;
34 	}
35 };
36 
37 
38 static int32
get_usage_infos(thread_info * infos)39 get_usage_infos(thread_info* infos)
40 {
41 	int32 count = 0;
42 
43 	int32 teamCookie = 0;
44 	team_info teamInfo;
45 	while (get_next_team_info(&teamCookie, &teamInfo) == B_OK) {
46 		int32 threadCookie = 0;
47 		while (get_next_thread_info(teamInfo.team, &threadCookie, &infos[count])
48 				== B_OK) {
49 			count++;
50 		}
51 	}
52 
53 	return count;
54 }
55 
56 
57 static pid_t
run_child(int argc,const char * const * argv)58 run_child(int argc, const char* const* argv)
59 {
60 	// fork
61 	pid_t child = fork();
62 	if (child < 0) {
63 		fprintf(stderr, "Error: fork() failed: %s\n", strerror(errno));
64 		exit(1);
65 	}
66 
67 	// exec child process
68 	if (child == 0) {
69 		execvp(argv[0], (char**)argv);
70 		exit(1);
71 	}
72 
73 	// wait for child
74 	int childStatus;
75 	while (wait(&childStatus) < 0);
76 
77 	return child;
78 }
79 
80 
81 void
do_timing_analysis(int argc,const char * const * argv,bool schedulingAnalysis,int outFD,size_t bufferSize)82 do_timing_analysis(int argc, const char* const* argv, bool schedulingAnalysis,
83 	int outFD, size_t bufferSize)
84 {
85 	// gather initial usage info
86 	thread_info initialUsage[MAX_THREADS];
87 	int32 initialUsageCount = get_usage_infos(initialUsage);
88 
89 	// exec child process
90 	bigtime_t startTime = system_time();
91 	pid_t child = run_child(argc, argv);
92 
93 	// get child usage info
94 	bigtime_t endTime = system_time();
95 	bigtime_t runTime = endTime - startTime;
96 	team_usage_info childUsage;
97 	get_team_usage_info(B_CURRENT_TEAM, B_TEAM_USAGE_CHILDREN, &childUsage);
98 
99 	// gather final usage info
100 	thread_info finalUsage[MAX_THREADS];
101 	int32 finalUsageCount = get_usage_infos(finalUsage);
102 
103 	// sort the infos, so we can compare them better
104 	std::sort(initialUsage, initialUsage + initialUsageCount,
105 		UsageInfoThreadComparator());
106 	std::sort(finalUsage, finalUsage + finalUsageCount,
107 		UsageInfoThreadComparator());
108 
109 	// compute results
110 
111 	thread_info sortedThreads[MAX_THREADS];
112 	int32 sortedThreadCount = 0;
113 	thread_info goneThreads[MAX_THREADS];
114 	int32 goneThreadCount = 0;
115 
116 	// child
117 	sortedThreads[0].thread = child;
118 	sortedThreads[0].user_time = childUsage.user_time;
119 	sortedThreads[0].kernel_time = childUsage.kernel_time;
120 	strlcpy(sortedThreads[0].name, "<child>", sizeof(sortedThreads[0].name));
121 	sortedThreadCount++;
122 
123 	// other threads
124 	int32 initialI = 0;
125 	int32 finalI = 0;
126 	while (initialI < initialUsageCount || finalI < finalUsageCount) {
127 		if (initialI >= initialUsageCount
128 			|| (finalI < finalUsageCount
129 				&& initialUsage[initialI].thread > finalUsage[finalI].thread)) {
130 			// new thread
131 			memcpy(&sortedThreads[sortedThreadCount], &finalUsage[finalI],
132 				sizeof(thread_info));
133 			sortedThreadCount++;
134 			finalI++;
135 			continue;
136 		}
137 
138 		if (finalI >= finalUsageCount
139 			|| (initialI < initialUsageCount
140 				&& initialUsage[initialI].thread < finalUsage[finalI].thread)) {
141 			// gone thread
142 			memcpy(&goneThreads[goneThreadCount], &initialUsage[initialI],
143 				sizeof(thread_info));
144 			goneThreadCount++;
145 			initialI++;
146 			continue;
147 		}
148 
149 		// thread is still there
150 		memcpy(&sortedThreads[sortedThreadCount], &finalUsage[finalI],
151 			sizeof(thread_info));
152 		sortedThreads[sortedThreadCount].user_time
153 			-= initialUsage[initialI].user_time;
154 		sortedThreads[sortedThreadCount].kernel_time
155 			-= initialUsage[initialI].kernel_time;
156 		sortedThreadCount++;
157 		initialI++;
158 		finalI++;
159 	}
160 
161 	// sort results
162 	std::sort(sortedThreads, sortedThreads + sortedThreadCount,
163 		UsageInfoTimeComparator());
164 
165 	// redirect output, if requested
166 	if (outFD >= 0)
167 		dup2(outFD, STDOUT_FILENO);
168 
169 	// print results
170 	printf("\nTotal run time: %lld us\n", runTime);
171 	printf("Thread time statistics in us:\n\n");
172 	printf(" thread  name                                  kernel        user  "
173 		"     total    in %%\n");
174 	printf("-------------------------------------------------------------------"
175 		"------------------\n");
176 
177 	for (int32 i = 0; i < sortedThreadCount; i++) {
178 		const thread_info& info = sortedThreads[i];
179 		if (info.user_time + info.kernel_time == 0)
180 			break;
181 
182 		bool highlight = info.thread == child && isatty(STDOUT_FILENO);
183 
184 		if (highlight)
185 			printf("\033[1m");
186 
187 		bigtime_t total = info.user_time + info.kernel_time;
188 		printf("%7ld  %-32s  %10lld  %10lld  %10lld  %6.2f\n", info.thread,
189 			info.name, info.kernel_time, info.user_time, total,
190 			(double)total / runTime * 100);
191 
192 		if (highlight)
193 			printf("\033[m");
194 	}
195 
196 	for (int32 i = 0; i < goneThreadCount; i++) {
197 		const thread_info& info = goneThreads[i];
198 		printf("%7ld  %-32s  <gone>\n", info.thread, info.name);
199 	}
200 
201 	if (schedulingAnalysis)
202 		do_scheduling_analysis(startTime, endTime, bufferSize);
203 }
204