xref: /haiku/src/bin/debug/scheduling_recorder/scheduling_recorder.cpp (revision 686e891cd262340afe592ded7cfc87366248b5c7)
1 /*
2  * Copyright 2009, Ingo Weinhold, ingo_weinhold@gmx.de.
3  * Distributed under the terms of the MIT License.
4  */
5 
6 
7 #include <errno.h>
8 #include <fcntl.h>
9 #include <getopt.h>
10 #include <stdio.h>
11 #include <stdlib.h>
12 #include <string.h>
13 #include <sys/stat.h>
14 #include <unistd.h>
15 
16 #include <File.h>
17 
18 #include <syscalls.h>
19 #include <system_profiler_defs.h>
20 
21 #include <DebugEventStream.h>
22 
23 #include "debug_utils.h"
24 
25 
26 #define SCHEDULING_RECORDING_AREA_SIZE	(4 * 1024 * 1024)
27 
28 #define DEBUG_EVENT_MASK \
29 	(B_SYSTEM_PROFILER_TEAM_EVENTS | B_SYSTEM_PROFILER_THREAD_EVENTS	\
30 		| B_SYSTEM_PROFILER_SCHEDULING_EVENTS							\
31 		| B_SYSTEM_PROFILER_IO_SCHEDULING_EVENTS)
32 
33 
34 extern const char* __progname;
35 const char* kCommandName = __progname;
36 
37 
38 static const char* kUsage =
39 	"Usage: %s [ <options> ] <output file> [ <command line> ]\n"
40 	"Records thread scheduling information to a file for later analysis.\n"
41 	"If a command line <command line> is given, recording starts right before\n"
42 	"executing the command and stops when the respective team quits.\n"
43 	"\n"
44 	"Options:\n"
45 	"  -l           - When a command line is given: Start recording before\n"
46 	"                 executable has been loaded.\n"
47 	"  -r           - Don't profile, but evaluate recorded kernel profile data.\n"
48 	"  -h, --help   - Print this usage info.\n"
49 ;
50 
51 
52 static void
print_usage_and_exit(bool error)53 print_usage_and_exit(bool error)
54 {
55     fprintf(error ? stderr : stdout, kUsage, kCommandName);
56     exit(error ? 1 : 0);
57 }
58 
59 
60 class Recorder {
61 public:
Recorder()62 	Recorder()
63 		:
64 		fMainTeam(-1),
65 		fSkipLoading(true),
66 		fCaughtDeadlySignal(false)
67 	{
68 	}
69 
~Recorder()70 	~Recorder()
71 	{
72 		fOutput.Flush();
73 	}
74 
75 
Init(const char * outputFile)76 	status_t Init(const char* outputFile)
77 	{
78 		// open file
79 		status_t error = fOutputFile.SetTo(outputFile,
80 			B_READ_WRITE | B_CREATE_FILE | B_ERASE_FILE);
81 		if (error != B_OK) {
82 			fprintf(stderr, "Error: Failed to open \"%s\": %s\n", outputFile,
83 				strerror(error));
84 			return error;
85 		}
86 
87 		// create output stream
88 		error = fOutput.SetTo(&fOutputFile, 0, DEBUG_EVENT_MASK);
89 		if (error != B_OK) {
90 			fprintf(stderr, "Error: Failed to initialize the output "
91 				"stream: %s\n", strerror(error));
92 			return error;
93 		}
94 
95 		return B_OK;
96 	}
97 
SetSkipLoading(bool skipLoading)98 	void SetSkipLoading(bool skipLoading)
99 	{
100 		fSkipLoading = skipLoading;
101 	}
102 
Run(const char * const * programArgs,int programArgCount)103 	void Run(const char* const* programArgs, int programArgCount)
104 	{
105 		// Load the executable, if we have to.
106 		thread_id threadID = -1;
107 		if (programArgCount >= 1) {
108 			threadID = load_program(programArgs, programArgCount,
109 				!fSkipLoading);
110 			if (threadID < 0) {
111 				fprintf(stderr, "%s: Failed to start `%s': %s\n", kCommandName,
112 					programArgs[0], strerror(threadID));
113 				exit(1);
114 			}
115 			fMainTeam = threadID;
116 		}
117 
118 		// install signal handlers so we can exit gracefully
119 		struct sigaction action;
120 		action.sa_handler = (__sighandler_t)_SignalHandler;
121 		action.sa_flags = 0;
122 		sigemptyset(&action.sa_mask);
123 		action.sa_userdata = this;
124 		if (sigaction(SIGHUP, &action, NULL) < 0
125 			|| sigaction(SIGINT, &action, NULL) < 0
126 			|| sigaction(SIGQUIT, &action, NULL) < 0) {
127 			fprintf(stderr, "%s: Failed to install signal handlers: %s\n",
128 				kCommandName, strerror(errno));
129 			exit(1);
130 		}
131 
132 		// create an area for the sample buffer
133 		system_profiler_buffer_header* bufferHeader;
134 		area_id area = create_area("profiling buffer", (void**)&bufferHeader,
135 			B_ANY_ADDRESS, SCHEDULING_RECORDING_AREA_SIZE, B_NO_LOCK,
136 			B_READ_AREA | B_WRITE_AREA);
137 		if (area < 0) {
138 			fprintf(stderr, "%s: Failed to create sample area: %s\n",
139 				kCommandName, strerror(area));
140 			exit(1);
141 		}
142 
143 		uint8* bufferBase = (uint8*)(bufferHeader + 1);
144 		size_t totalBufferSize = SCHEDULING_RECORDING_AREA_SIZE
145 			- (bufferBase - (uint8*)bufferHeader);
146 
147 		// start profiling
148 		system_profiler_parameters profilerParameters;
149 		profilerParameters.buffer_area = area;
150 		profilerParameters.flags = DEBUG_EVENT_MASK;
151 		profilerParameters.locking_lookup_size = 64 * 1024;
152 
153 		status_t error = _kern_system_profiler_start(&profilerParameters);
154 		if (error != B_OK) {
155 			fprintf(stderr, "%s: Failed to start profiling: %s\n", kCommandName,
156 				strerror(error));
157 			exit(1);
158 		}
159 
160 		// resume the loaded team, if we have one
161 		if (threadID >= 0)
162 			resume_thread(threadID);
163 
164 		// main event loop
165 		while (true) {
166 			// get the current buffer
167 			size_t bufferStart = bufferHeader->start;
168 			size_t bufferSize = bufferHeader->size;
169 			uint8* buffer = bufferBase + bufferStart;
170 //printf("processing buffer of size %lu bytes\n", bufferSize);
171 
172 			bool quit;
173 			if (bufferStart + bufferSize <= totalBufferSize) {
174 				quit = _ProcessEventBuffer(buffer, bufferSize);
175 			} else {
176 				size_t remainingSize = bufferStart + bufferSize
177 					- totalBufferSize;
178 				quit = _ProcessEventBuffer(buffer, bufferSize - remainingSize)
179 					|| _ProcessEventBuffer(bufferBase, remainingSize);
180 			}
181 
182 			if (quit || fCaughtDeadlySignal)
183 				break;
184 
185 			// get next buffer
186 			uint64 droppedEvents = 0;
187 			error = _kern_system_profiler_next_buffer(bufferSize,
188 				&droppedEvents);
189 
190 			if (error != B_OK) {
191 				if (error == B_INTERRUPTED)
192 					continue;
193 
194 				fprintf(stderr, "%s: Failed to get next sample buffer: %s\n",
195 					kCommandName, strerror(error));
196 				break;
197 			}
198 
199 			if (droppedEvents > 0)
200 				fprintf(stderr, "%llu events dropped\n", droppedEvents);
201 		}
202 
203 		// stop profiling
204 		_kern_system_profiler_stop();
205 	}
206 
DumpRecorded()207 	void DumpRecorded()
208 	{
209 		// retrieve recorded samples and parameters
210 		system_profiler_parameters profilerParameters;
211 		status_t error = _kern_system_profiler_recorded(&profilerParameters);
212 		if (error != B_OK) {
213 			fprintf(stderr, "%s: Failed to get recorded profiling buffer: %s\n",
214 				kCommandName, strerror(error));
215 			exit(1);
216 		}
217 
218 		// create an area for the sample buffer
219 		area_info info;
220 		error = get_area_info(profilerParameters.buffer_area, &info);
221 		if (error != B_OK) {
222 			fprintf(stderr, "%s: Recorded profiling buffer invalid: %s\n",
223 				kCommandName, strerror(error));
224 			exit(1);
225 		}
226 
227 		system_profiler_buffer_header* bufferHeader
228 			= (system_profiler_buffer_header*)info.address;
229 
230 		uint8* bufferBase = (uint8*)(bufferHeader + 1);
231 		size_t totalBufferSize = info.size - (bufferBase - (uint8*)bufferHeader);
232 
233 		// get the current buffer
234 		size_t bufferStart = bufferHeader->start;
235 		size_t bufferSize = bufferHeader->size;
236 		uint8* buffer = bufferBase + bufferStart;
237 
238 		if (bufferStart + bufferSize <= totalBufferSize) {
239 			_ProcessEventBuffer(buffer, bufferSize);
240 		} else {
241 			size_t remainingSize = bufferStart + bufferSize - totalBufferSize;
242 			if (!_ProcessEventBuffer(buffer,
243 					bufferSize - remainingSize)) {
244 				_ProcessEventBuffer(bufferBase, remainingSize);
245 			}
246 		}
247 	}
248 
249 private:
_ProcessEventBuffer(uint8 * buffer,size_t bufferSize)250 	bool _ProcessEventBuffer(uint8* buffer, size_t bufferSize)
251 	{
252 //printf("_ProcessEventBuffer(%p, %lu)\n", buffer, bufferSize);
253 		const uint8* bufferStart = buffer;
254 		const uint8* bufferEnd = buffer + bufferSize;
255 		size_t usableBufferSize = bufferSize;
256 		bool quit = false;
257 
258 		while (buffer < bufferEnd) {
259 			system_profiler_event_header* header
260 				= (system_profiler_event_header*)buffer;
261 
262 			buffer += sizeof(system_profiler_event_header);
263 
264 			if (header->event == B_SYSTEM_PROFILER_BUFFER_END) {
265 				// Marks the end of the ring buffer -- we need to ignore the
266 				// remaining bytes.
267 				usableBufferSize = (uint8*)header - bufferStart;
268 				break;
269 			}
270 
271 			if (header->event == B_SYSTEM_PROFILER_TEAM_REMOVED) {
272 				system_profiler_team_removed* event
273 					= (system_profiler_team_removed*)buffer;
274 
275 				// quit, if the main team we're interested in is gone
276 				if (fMainTeam >= 0 && event->team == fMainTeam) {
277 					usableBufferSize = buffer + header->size - bufferStart;
278 					quit = true;
279 					break;
280 				}
281 			}
282 
283 			buffer += header->size;
284 		}
285 
286 		// write buffer to file
287 		if (usableBufferSize > 0) {
288 			status_t error = fOutput.Write(bufferStart, usableBufferSize);
289 			if (error != B_OK) {
290 				fprintf(stderr, "%s: Failed to write buffer: %s\n",
291 					kCommandName, strerror(error));
292 				quit = true;
293 			}
294 		}
295 
296 		return quit;
297 	}
298 
299 
_SignalHandler(int signal,void * data)300 	static void _SignalHandler(int signal, void* data)
301 	{
302 		Recorder* self = (Recorder*)data;
303 		self->fCaughtDeadlySignal = true;
304 	}
305 
306 private:
307 	BFile					fOutputFile;
308 	BDebugEventOutputStream	fOutput;
309 	team_id					fMainTeam;
310 	bool					fSkipLoading;
311 	bool					fCaughtDeadlySignal;
312 };
313 
314 
315 int
main(int argc,const char * const * argv)316 main(int argc, const char* const* argv)
317 {
318 	Recorder recorder;
319 
320 	bool dumpRecorded = false;
321 	while (true) {
322 		static struct option sLongOptions[] = {
323 			{ "help", no_argument, 0, 'h' },
324 			{ 0, 0, 0, 0 }
325 		};
326 
327 		opterr = 0; // don't print errors
328 		int c = getopt_long(argc, (char**)argv, "+hlr", sLongOptions, NULL);
329 		if (c == -1)
330 			break;
331 
332 		switch (c) {
333 			case 'h':
334 				print_usage_and_exit(false);
335 				break;
336 			case 'l':
337 				recorder.SetSkipLoading(false);
338 				break;
339 
340 			case 'r':
341 				dumpRecorded = true;
342 				break;
343 
344 			default:
345 				print_usage_and_exit(true);
346 				break;
347 		}
348 	}
349 
350 	// Remaining arguments should be the output file and the optional command
351 	// line.
352 	if (optind >= argc)
353 		print_usage_and_exit(true);
354 
355 	const char* outputFile = argv[optind++];
356 	const char* const* programArgs = argv + optind;
357 	int programArgCount = argc - optind;
358 
359 	// prepare for battle
360 	if (recorder.Init(outputFile) != B_OK)
361 		exit(1);
362 
363 	// start the action
364 	if (!dumpRecorded)
365 		recorder.Run(programArgs, programArgCount);
366 	else
367 		recorder.DumpRecorded();
368 
369 	return 0;
370 }
371