xref: /minix3/minix/usr.bin/trace/call.c (revision ace2de0ad1d8e59d59cc17c1a9b69743a509c2c6)
1  
2  #include "inc.h"
3  
4  #include <minix/com.h>
5  #include <minix/callnr.h>
6  #include <minix/endpoint.h>
7  
8  static const struct calls *call_table[] = {
9  	&pm_calls,
10  	&vfs_calls,
11  	&rs_calls,
12  	&mib_calls,
13  	&vm_calls,
14  	&ipc_calls,
15  };
16  
17  /*
18   * Find a call handler for the given endpoint, call number pair.  Return NULL
19   * if no call handler for this call exists.
20   */
21  static const struct call_handler *
22  find_handler(endpoint_t endpt, int call_nr)
23  {
24  	unsigned int i, index;
25  
26  	for (i = 0; i < COUNT(call_table); i++) {
27  		if (call_table[i]->endpt != ANY &&
28  		    call_table[i]->endpt != endpt)
29  			continue;
30  
31  		if ((unsigned int)call_nr < call_table[i]->base)
32  			continue;
33  
34  		index = (unsigned int)call_nr - call_table[i]->base;
35  
36  		if (index >= call_table[i]->count)
37  			continue;
38  
39  		if (call_table[i]->map[index].outfunc == NULL)
40  			continue;
41  
42  		return &call_table[i]->map[index];
43  	}
44  
45  	return NULL;
46  }
47  
48  /*
49   * Print an endpoint.
50   */
51  void
52  put_endpoint(struct trace_proc * proc, const char * name, endpoint_t endpt)
53  {
54  	const char *text = NULL;
55  
56  	if (!valuesonly) {
57  		switch (endpt) {
58  		TEXT(ASYNCM);
59  		TEXT(IDLE);
60  		TEXT(CLOCK);
61  		TEXT(SYSTEM);
62  		TEXT(KERNEL);
63  		TEXT(PM_PROC_NR);
64  		TEXT(VFS_PROC_NR);
65  		TEXT(RS_PROC_NR);
66  		TEXT(MEM_PROC_NR);
67  		TEXT(SCHED_PROC_NR);
68  		TEXT(TTY_PROC_NR);
69  		TEXT(DS_PROC_NR);
70  		TEXT(MIB_PROC_NR);
71  		TEXT(VM_PROC_NR);
72  		TEXT(PFS_PROC_NR);
73  		TEXT(ANY);
74  		TEXT(NONE);
75  		TEXT(SELF);
76  		}
77  	}
78  
79  	if (text != NULL)
80  		put_field(proc, name, text);
81  	else
82  		put_value(proc, name, "%d", endpt);
83  }
84  
85  /*
86   * Print a message structure.  The source field will be printed only if the
87   * PF_ALT flag is given.
88   */
89  static void
90  put_message(struct trace_proc * proc, const char * name, int flags,
91  	vir_bytes addr)
92  {
93  	message m;
94  
95  	if (!put_open_struct(proc, name, flags, addr, &m, sizeof(m)))
96  		return;
97  
98  	if (flags & PF_ALT)
99  		put_endpoint(proc, "m_source", m.m_source);
100  
101  	put_value(proc, "m_type", "%x", m.m_type);
102  
103  	put_close_struct(proc, FALSE /*all*/);
104  }
105  
106  /*
107   * Print the call's equals sign, which also implies that the parameters part of
108   * the call has been fully printed and the corresponding closing parenthesis
109   * may have to be printed, if it has not been printed already.
110   */
111  void
112  put_equals(struct trace_proc * proc)
113  {
114  
115  	/*
116  	 * Do not allow multiple equals signs on a single line.  This check is
117  	 * protection against badly written handlers.  It does not work for the
118  	 * no-return type, but such calls are rare and less error prone anyway.
119  	 */
120  	assert((proc->call_flags & (CF_DONE | CF_NORETURN)) != CF_DONE);
121  
122  	/*
123  	 * We allow (and in fact force) handlers to call put_equals in order to
124  	 * indicate that the call's parameters block has ended, so we must end
125  	 * the block here, if we hadn't done so before.
126  	 */
127  	if (!(proc->call_flags & CF_DONE)) {
128  		put_close(proc, ") ");
129  
130  		proc->call_flags |= CF_DONE;
131  	}
132  
133  	put_align(proc);
134  	put_text(proc, "= ");
135  
136  	format_set_sep(proc, NULL);
137  }
138  
139  /*
140   * Print the primary result of a call, after the equals sign.  It is always
141   * possible that this is an IPC-level or other low-level error, in which case
142   * this takes precedence, which is why this function must be called to print
143   * the result if the call failed in any way at all; it may or may not be used
144   * if the call succeeded.  For regular call results, default MINIX3/POSIX
145   * semantics are used: if the return value is negative, the actual call failed
146   * with -1 and the negative return value is the call's error code.  The caller
147   * may consider other cases a failure (e.g., waitpid() returning 0), but
148   * negative return values *not* signifying an error are currently not supported
149   * since they are not present in MINIX3.
150   */
151  void
152  put_result(struct trace_proc * proc)
153  {
154  	const char *errname;
155  	int value;
156  
157  	/* This call should always be preceded by a put_equals call. */
158  	assert(proc->call_flags & CF_DONE);
159  
160  	/*
161  	 * If we failed to copy in the result register or message, print a
162  	 * basic error and nothing else.
163  	 */
164  	if (proc->call_flags & (CF_REG_ERR | CF_MSG_ERR)) {
165  		put_text(proc, "<fault>");
166  
167  		return;
168  	}
169  
170  	/*
171  	 * If we are printing a system call rather than an IPC call, and an
172  	 * error occurred at the IPC level, prefix the output with "<ipc>" to
173  	 * indicate the IPC failure.  If we are printing an IPC call, an IPC-
174  	 * level result is implied, so we do not print this.
175  	 */
176  	if (proc->call_handler != NULL && (proc->call_flags & CF_IPC_ERR))
177  		put_text(proc, "<ipc> ");
178  
179  	value = proc->call_result;
180  
181  	if (value >= 0)
182  		put_fmt(proc, "%d", value);
183  	else if (!valuesonly && (errname = get_error_name(-value)) != NULL)
184  		put_fmt(proc, "-1 [%s]", errname);
185  	else
186  		put_fmt(proc, "-1 [%d]", -value);
187  
188  	format_set_sep(proc, " ");
189  }
190  
191  /*
192   * The default enter-call (out) printer, which prints no parameters and is thus
193   * immediately done with printing parameters.
194   */
195  int
196  default_out(struct trace_proc * __unused proc, const message * __unused m_out)
197  {
198  
199  	return CT_DONE;
200  }
201  
202  /*
203   * The default leave-call (in) printer, which simply prints the call result,
204   * possibly preceded by an equals sign if none was printed yet.  For obvious
205   * reasons, if the handler's out printer returned CT_NOTDONE, this default
206   * printer must not be used.
207   */
208  void
209  default_in(struct trace_proc * proc, const message * __unused m_out,
210  	const message * __unused m_in, int __unused failed)
211  {
212  
213  	if ((proc->call_flags & (CF_DONE | CF_NORETURN)) != CF_DONE)
214  		put_equals(proc);
215  	put_result(proc);
216  }
217  
218  /*
219   * Prepare a sendrec call, by copying in the request message, determining
220   * whether it is one of the calls that the tracing engine should know about,
221   * searching for a handler for the call, and returning a name for the call.
222   */
223  static const char *
224  sendrec_prepare(struct trace_proc * proc, endpoint_t endpt, vir_bytes addr,
225  	int * trace_class)
226  {
227  	const char *name;
228  	int r;
229  
230  	r = mem_get_data(proc->pid, addr, &proc->m_out, sizeof(proc->m_out));
231  
232  	if (r == 0) {
233  		if (endpt == PM_PROC_NR) {
234  			if (proc->m_out.m_type == PM_EXEC)
235  				*trace_class = TC_EXEC;
236  			else if (proc->m_out.m_type == PM_SIGRETURN)
237  				*trace_class = TC_SIGRET;
238  		}
239  
240  		proc->call_handler = find_handler(endpt, proc->m_out.m_type);
241  	} else
242  		proc->call_handler = NULL;
243  
244  	if (proc->call_handler != NULL) {
245  		if (proc->call_handler->namefunc != NULL)
246  			name = proc->call_handler->namefunc(&proc->m_out);
247  		else
248  			name = proc->call_handler->name;
249  
250  		assert(name != NULL);
251  	} else
252  		name = "ipc_sendrec";
253  
254  	return name;
255  }
256  
257  /*
258   * Print the outgoing (request) part of a sendrec call.  If we found a call
259   * handler for the call, let the handler generate output.  Otherwise, print the
260   * sendrec call at the kernel IPC level.  Return the resulting call flags.
261   */
262  static unsigned int
263  sendrec_out(struct trace_proc * proc, endpoint_t endpt, vir_bytes addr)
264  {
265  
266  	if (proc->call_handler != NULL) {
267  		return proc->call_handler->outfunc(proc, &proc->m_out);
268  	} else {
269  		put_endpoint(proc, "src_dest", endpt);
270  		/*
271  		 * We have already copied in the message, but if we used m_out
272  		 * and PF_LOCADDR here, a copy failure would cause "&.." to be
273  		 * printed rather than the actual message address.
274  		 */
275  		put_message(proc, "m_ptr", 0, addr);
276  
277  		return CT_DONE;
278  	}
279  }
280  
281  /*
282   * Print the incoming (reply) part of a sendrec call.  Copy in the reply
283   * message, determine whether the call is considered to have failed, and let
284   * the call handler do the rest.  If no call handler was found, print an
285   * IPC-level result.
286   */
287  static void
288  sendrec_in(struct trace_proc * proc, int failed)
289  {
290  	message m_in;
291  
292  	if (failed) {
293  		/* The call failed at the IPC level. */
294  		memset(&m_in, 0, sizeof(m_in)); /* not supposed to be used */
295  		assert(proc->call_flags & CF_IPC_ERR);
296  	} else if (mem_get_data(proc->pid, proc->m_addr, &m_in,
297  	    sizeof(m_in)) != 0) {
298  		/* The reply message is somehow unavailable to us. */
299  		memset(&m_in, 0, sizeof(m_in)); /* not supposed to be used */
300  		proc->call_result = EGENERIC; /* not supposed to be used */
301  		proc->call_flags |= CF_MSG_ERR;
302  		failed = PF_FAILED;
303  	} else {
304  		/* The result is for the actual call. */
305  		proc->call_result = m_in.m_type;
306  		failed = (proc->call_result < 0) ? PF_FAILED : 0;
307  	}
308  
309  	if (proc->call_handler != NULL)
310  		proc->call_handler->infunc(proc, &proc->m_out, &m_in, failed);
311  	else
312  		put_result(proc);
313  }
314  
315  /*
316   * Perform preparations for printing a system call.  Return two things: the
317   * name to use for the call, and the trace class of the call.
318   * special treatment).
319   */
320  static const char *
321  call_prepare(struct trace_proc * proc, reg_t reg[3], int * trace_class)
322  {
323  
324  	switch (proc->call_type) {
325  	case SENDREC:
326  		return sendrec_prepare(proc, (endpoint_t)reg[1],
327  		    (vir_bytes)reg[2], trace_class);
328  
329  	case SEND:
330  		return "ipc_send";
331  
332  	case SENDNB:
333  		return "ipc_sendnb";
334  
335  	case RECEIVE:
336  		return "ipc_receive";
337  
338  	case NOTIFY:
339  		return "ipc_notify";
340  
341  	case SENDA:
342  		return "ipc_senda";
343  
344  	case MINIX_KERNINFO:
345  		return "minix_kerninfo";
346  
347  	default:
348  		/*
349  		 * It would be nice to include the call number here, but we
350  		 * must return a string that will last until the entire call is
351  		 * finished.  Adding another buffer to the trace_proc structure
352  		 * is an option, but it seems overkill..
353  		 */
354  		return "ipc_unknown";
355  	}
356  }
357  
358  /*
359   * Print the outgoing (request) part of a system call.  Return the resulting
360   * call flags.
361   */
362  static unsigned int
363  call_out(struct trace_proc * proc, reg_t reg[3])
364  {
365  
366  	switch (proc->call_type) {
367  	case SENDREC:
368  		proc->m_addr = (vir_bytes)reg[2];
369  
370  		return sendrec_out(proc, (endpoint_t)reg[1],
371  		    (vir_bytes)reg[2]);
372  
373  	case SEND:
374  	case SENDNB:
375  		put_endpoint(proc, "dest", (endpoint_t)reg[1]);
376  		put_message(proc, "m_ptr", 0, (vir_bytes)reg[2]);
377  
378  		return CT_DONE;
379  
380  	case RECEIVE:
381  		proc->m_addr = (vir_bytes)reg[2];
382  
383  		put_endpoint(proc, "src", (endpoint_t)reg[1]);
384  
385  		return CT_NOTDONE;
386  
387  	case NOTIFY:
388  		put_endpoint(proc, "dest", (endpoint_t)reg[1]);
389  
390  		return CT_DONE;
391  
392  	case SENDA:
393  		put_ptr(proc, "table", (vir_bytes)reg[2]);
394  		put_value(proc, "count", "%zu", (size_t)reg[1]);
395  
396  		return CT_DONE;
397  
398  	case MINIX_KERNINFO:
399  	default:
400  		return CT_DONE;
401  	}
402  }
403  
404  /*
405   * Print the incoming (reply) part of a call.
406   */
407  static void
408  call_in(struct trace_proc * proc, int failed)
409  {
410  
411  	switch (proc->call_type) {
412  	case SENDREC:
413  		sendrec_in(proc, failed);
414  
415  		break;
416  
417  	case RECEIVE:
418  		/* Print the source as well. */
419  		put_message(proc, "m_ptr", failed | PF_ALT, proc->m_addr);
420  		put_equals(proc);
421  		put_result(proc);
422  
423  		break;
424  
425  	case MINIX_KERNINFO:
426  		/*
427  		 * We do not have a platform-independent means to access the
428  		 * secondary IPC return value, so we cannot print the receive
429  		 * status or minix_kerninfo address.
430  		 */
431  		/* FALLTHROUGH */
432  	default:
433  		put_result(proc);
434  
435  		break;
436  	}
437  }
438  
439  /*
440   * Determine whether to skip printing the given call, based on its name.
441   */
442  static int
443  call_hide(const char * __unused name)
444  {
445  
446  	/*
447  	 * TODO: add support for such filtering, with an strace-like -e command
448  	 * line option.  For now, we filter nothing, although calls may still
449  	 * be hidden as the result of a register retrieval error.
450  	 */
451  	return FALSE;
452  }
453  
454  /*
455   * The given process entered a system call.  Return the trace class of the
456   * call: TC_EXEC for an execve() call, TC_SIGRET for a sigreturn() call, or
457   * TC_NORMAL for a call that requires no exceptions in the trace engine.
458   */
459  int
460  call_enter(struct trace_proc * proc, int show_stack)
461  {
462  	const char *name;
463  	reg_t reg[3];
464  	int trace_class, type;
465  
466  	/* Get the IPC-level type and parameters of the system call. */
467  	if (kernel_get_syscall(proc->pid, reg) < 0) {
468  		/*
469  		 * If obtaining the details of the system call failed, even
470  		 * though we know the process is stopped on a system call, we
471  		 * are going to assume that the process got killed somehow.
472  		 * Thus, the best we can do is ignore the system call entirely,
473  		 * and hope that the next thing we hear about this process is
474  		 * its termination.  At worst, we ignore a serious error..
475  		 */
476  		proc->call_flags = CF_HIDE;
477  
478  		return FALSE;
479  	}
480  
481  	/*
482  	 * Obtain the call name that is to be used for this call, and decide
483  	 * whether we want to print this call at all.
484  	 */
485  	proc->call_type = (int)reg[0];
486  	trace_class = TC_NORMAL;
487  
488  	name = call_prepare(proc, reg, &trace_class);
489  
490  	proc->call_name = name;
491  
492  	if (call_hide(name)) {
493  		proc->call_flags = CF_HIDE;
494  
495  		return trace_class;
496  	}
497  
498  	/* Only print a stack trace if we are printing the call itself. */
499  	if (show_stack)
500  		kernel_put_stacktrace(proc);
501  
502  	/*
503  	 * Start a new line, start recording, and print the call name and
504  	 * opening parenthesis.
505  	 */
506  	put_newline();
507  
508  	format_reset(proc);
509  
510  	record_start(proc);
511  
512  	put_text(proc, name);
513  	put_open(proc, NULL, PF_NONAME, "(", ", ");
514  
515  	/*
516  	 * Print the outgoing part of the call, that is, some or all of its
517  	 * parameters.  This call returns flags indicating how far printing
518  	 * got, and may be one of the following combinations:
519  	 * - CT_NOTDONE (0) if printing parameters is not yet complete; after
520  	 *   the call split, the in handler must print the rest itself;
521  	 * - CT_DONE (CF_DONE) if printing parameters is complete, and we
522  	 *   should now print the closing parenthesis and equals sign;
523  	 * - CT_NORETURN (CF_DONE|CF_NORETURN) if printing parameters is
524  	 *   complete, but we should not print the equals sign, because the
525  	 *   call is expected not to return (the no-return call type).
526  	 */
527  	type = call_out(proc, reg);
528  	assert(type == CT_NOTDONE || type == CT_DONE || type == CT_NORETURN);
529  
530  	/*
531  	 * Print whatever the handler told us to print for now.
532  	 */
533  	if (type & CF_DONE) {
534  		if (type & CF_NORETURN) {
535  			put_close(proc, ")");
536  
537  			put_space(proc);
538  
539  			proc->call_flags |= type;
540  		} else {
541  			/*
542  			 * The equals sign is printed implicitly for the
543  			 * CT_DONE type only.  For CT_NORETURN and CT_NOTDONE,
544  			 * the "in" handler has to do it explicitly.
545  			 */
546  			put_equals(proc);
547  		}
548  	} else {
549  		/*
550  		 * If at least one parameter was printed, print the separator
551  		 * now.  We know that another parameter will follow (otherwise
552  		 * the caller would have returned CT_DONE), and this way the
553  		 * output looks better.
554  		 */
555  		format_push_sep(proc);
556  	}
557  
558  	/*
559  	 * We are now at the call split; further printing will be done once the
560  	 * call returns, through call_leave.  Stop recording; if the call gets
561  	 * suspended and later resumed, we should replay everything up to here.
562  	 */
563  #if DEBUG
564  	put_text(proc, "|"); /* warning, this may push a space */
565  #endif
566  
567  	record_stop(proc);
568  
569  	output_flush();
570  
571  	return trace_class;
572  }
573  
574  /*
575   * The given process left a system call, or if skip is set, the leave phase of
576   * the current system call should be ended.
577   */
578  void
579  call_leave(struct trace_proc * proc, int skip)
580  {
581  	reg_t retreg;
582  	int hide, failed;
583  
584  	/* If the call is skipped, it must be a no-return type call. */
585  	assert(!skip || (proc->call_flags & (CF_NORETURN | CF_HIDE)));
586  
587  	/*
588  	 * Start by replaying the current call, if necessary.  If the call was
589  	 * suspended and we are about to print the "in" part, this is obviously
590  	 * needed.  If the call is hidden, replaying will be a no-op, since
591  	 * nothing was recorded for this call.  The special case is a skipped
592  	 * call (which, as established above, must be a no-return call, e.g.
593  	 * exec), for which replaying has the effect that if the call was
594  	 * previously suspended, it will now be replayed, without suspension:
595  	 *
596  	 *       2| execve("./test", ["./test"], [..(12)]) <..>
597  	 *       3| sigsuspend([]) = <..>
598  	 * [A]   2| execve("./test", ["./test"], [..(12)])
599  	 *       2| ---
600  	 *       2| Tracing test (pid 2)
601  	 *
602  	 * The [A] line is the result of replaying the skipped call.
603  	 */
604  	call_replay(proc);
605  
606  	hide = (proc->call_flags & CF_HIDE);
607  
608  	if (!hide && !skip) {
609  		/* Get the IPC-level result of the call. */
610  		if (kernel_get_retreg(proc->pid, &retreg) < 0) {
611  			/* This should never happen.  Deal with it anyway. */
612  			proc->call_flags |= CF_REG_ERR;
613  			failed = PF_FAILED;
614  		} else if ((proc->call_result = (int)retreg) < 0) {
615  			proc->call_flags |= CF_IPC_ERR;
616  			failed = PF_FAILED;
617  		} else
618  			failed = 0;
619  
620  		/*
621  		 * Print the incoming part of the call, that is, possibly some
622  		 * or all of its parameters and the call's closing parenthesis
623  		 * (if CT_NOTDONE), and the equals sign (if not CT_DONE), then
624  		 * the call result.
625  		 */
626  		call_in(proc, failed);
627  	}
628  
629  	if (!hide) {
630  		/*
631  		 * The call is complete now, so clear the recording.  This also
632  		 * implies that no suspension marker will be printed anymore.
633  		 */
634  		record_clear(proc);
635  
636  		put_newline();
637  	}
638  
639  	/*
640  	 * For calls not of the no-return type, an equals sign must have been
641  	 * printed by now.  This is protection against badly written handlers.
642  	 */
643  	assert(proc->call_flags & CF_DONE);
644  
645  	proc->call_name = NULL;
646  	proc->call_flags = 0;
647  }
648  
649  /*
650   * Replay the recorded text, if any, for the enter phase of the given process.
651   * If there is no recorded text, start a new line anyway.
652   */
653  void
654  call_replay(struct trace_proc * proc)
655  {
656  
657  	/*
658  	 * We get TRUE if the recorded call should be replayed, but the
659  	 * recorded text for the call did not fit in the recording buffer.
660  	 * In that case, we have to come up with a replacement text for the
661  	 * call up to the call split.
662  	 */
663  	if (record_replay(proc) == TRUE) {
664  		/*
665  		 * We basically place a "<..>" suspension marker in the
666  		 * parameters part of the call, and use its call name and flags
667  		 * for the rest.  There is a trailing space in all cases.
668  		 */
669  		put_fmt(proc, "%s(<..>%s", proc->call_name,
670  		    !(proc->call_flags & CF_DONE) ? "," :
671  		    ((proc->call_flags & CF_NORETURN) ? ")" : ") ="));
672  		put_space(proc);
673  	}
674  }
675  
676  /*
677   * Return the human-readable name of the call currently being made by the given
678   * process.  The process is guaranteed to be in a call, although the call may
679   * be hidden.  Under no circumstances may this function return a NULL pointer.
680   */
681  const char *
682  call_name(struct trace_proc * proc)
683  {
684  
685  	assert(proc->call_name != NULL);
686  
687  	return proc->call_name;
688  }
689  
690  /*
691   * Return whether the current call failed due to an error at the system call
692   * level, and if so, return the error code as well.  May be called during the
693   * leave phase of a call only.
694   */
695  int
696  call_errno(struct trace_proc * proc, int * err)
697  {
698  
699  	if (proc->call_flags & (CF_REG_ERR | CF_MSG_ERR | CF_IPC_ERR))
700  		return FALSE;
701  
702  	if (proc->call_result >= 0)
703  		return FALSE;
704  
705  	*err = -proc->call_result;
706  	return TRUE;
707  }
708