Optional IPC logging

This commit is contained in:
Erik van der Kouwe 2010-06-24 13:31:40 +00:00
parent 3985311b2e
commit fe07e7c984
9 changed files with 210 additions and 1 deletions

View file

@ -32,3 +32,17 @@ MAN=
.include "system/Makefile.inc"
.include "arch/${ARCH}/Makefile.inc"
.include <minix.prog.mk>
debug.d: extracted-errno.h extracted-mfield.h extracted-mtype.h
extracted-errno.h: extract-errno.sh ../include/errno.h
sh extract-errno.sh > extracted-errno.h
extracted-mfield.h: extract-mfield.sh ../lib/libc/other/*.c ../lib/libc/posix/*.c ../lib/libsys/*.c
sh extract-mfield.sh > extracted-mfield.h
extracted-mtype.h: extract-mtype.sh ../include/minix/com.h
sh extract-mtype.sh > extracted-mtype.h
clean:
rm -f extracted-errno.h extracted-mfield.h extracted-mtype.h

View file

@ -7,6 +7,7 @@
#include "proc.h"
#include "debug.h"
#include <minix/callnr.h>
#include <minix/sysutil.h>
#include <limits.h>
#include <string.h>
@ -234,3 +235,89 @@ PUBLIC void print_proc_recursive(struct proc *pp)
print_proc_depends(pp, 0);
}
#if DEBUG_DUMPIPC
PRIVATE const char *mtypename(int mtype, int iscall)
{
/* use generated file to recognize message types */
if (iscall) {
switch(mtype) {
#define IDENT(x) case x: return #x;
#include "extracted-mtype.h"
#undef IDENT(
}
} else {
switch(mtype) {
#define IDENT(x) case x: return #x;
#include "extracted-errno.h"
#undef IDENT(
}
}
/* no match */
return NULL;
}
PRIVATE void printparam(const char *name, const void *data, size_t size)
{
printf(" %s=", name);
switch (size) {
case sizeof(char): printf("%d", *(char *) data); break;
case sizeof(short): printf("%d", *(short *) data); break;
case sizeof(int): printf("%d", *(int *) data); break;
default: printf("(%u bytes)", size); break;
}
}
PRIVATE void printproc(struct proc *rp)
{
if (rp)
printf(" %s(%d)", rp->p_name, rp - proc);
else
printf(" kernel");
}
PRIVATE void printmsg(message *msg, struct proc *src, struct proc *dst,
char operation, int iscall, int printparams)
{
const char *name;
int mtype = msg->m_type;
/* source, destination and message type */
printf("%c", operation);
printproc(src);
printproc(dst);
name = mtypename(mtype, iscall);
if (name) {
printf(" %s(%d)", name, mtype);
} else {
printf(" %d", mtype);
}
if (iscall && printparams) {
#define IDENT(x, y) if (mtype == x) printparam(#y, &msg->y, sizeof(msg->y));
#include "extracted-mfield.h"
#undef IDENT
}
printf("\n");
}
PUBLIC void printmsgkcall(message *msg, struct proc *proc)
{
printmsg(msg, proc, NULL, 'k', 1, 1);
}
PUBLIC void printmsgkresult(message *msg, struct proc *proc)
{
printmsg(msg, NULL, proc, 'k', 0, 0);
}
PUBLIC void printmsgrecv(message *msg, struct proc *src, struct proc *dst)
{
printmsg(msg, src, dst, 'r', src->p_misc_flags & MF_REPLY_PEND, 0);
}
PUBLIC void printmsgsend(message *msg, struct proc *src, struct proc *dst)
{
printmsg(msg, src, dst, 's', src->p_misc_flags & MF_REPLY_PEND, 1);
}
#endif

View file

@ -37,6 +37,13 @@
*/
#define DEBUG_RACE 0
/* DEBUG_DUMPIPC dumps all IPC to serial; due to the amount of logging it is
* strongly recommended to set "ctty 0" in the boot monitor and run inside a
* virtual machine if you enable this; on the hardware it would take forever
* just to boot
*/
#define DEBUG_DUMPIPC 0
#if DEBUG_TRACE
#define VF_SCHEDULING (1L << 1)

12
kernel/extract-errno.sh Normal file
View file

@ -0,0 +1,12 @@
#!/bin/sh
set -e
# grep message type and errno constants and make them into a .h file
cat ../include/errno.h | \
tr -s ' \t' ' ' | \
sed 's/^# /#/' | \
egrep '^#define [A-Z_][A-Z0-9_]* \( ?_SIGN ?[0-9]+ ?\)' | \
cut -d' ' -f2 | \
sed 's/\(.*\)/IDENT(\1)/' | \
sort

45
kernel/extract-mfield.sh Normal file
View file

@ -0,0 +1,45 @@
#!/bin/sh
set -e
find_files_and_lines()
(
find ../lib/libc/other ../lib/libc/posix ../lib/libsys -name '*.c' | \
xargs egrep -n '((_syscall|_taskcall)\([^,][^,]*,[ ]*|_kernel_call\()[A-Z_][A-Z0-9_]*,[ ]*&m\)' | \
cut -d: -f1,2
)
# grep message fields
(
# find references to _syscall, _taskcall and _kernel_call in the libraries
pathprev=
linecallprev=0
for f in `find_files_and_lines`
do
path="`echo $f | cut -d: -f1`"
linecall="`echo $f | cut -d: -f2`"
# find the matching message declaration; we can identify fields between message decl and call
linemsg=`head -n "$linecall" "$path" | egrep -n 'message[ ][ ]*m;' | tail -n 1 | cut -d: -f1`
if [ "x$linemsg" != "x" ]
then
# watch out: message may be re-used; start from last call in this case
[ \( "x$path" != "x$pathprev" \) -o \( "$linemsg" -gt "$linecallprev" \) ] || linemsg="$linecallprev"
# extract call name
callname=`head -n "$linecall" "$path" | tail -n 1 | sed 's/.*[ (,]\([A-Z_][A-Z0-9_]*\),[ ]*&m).*/\1/'`
# extract message fields
linelast="`expr "$linecall" - 1`"
linecount="`expr "$linelast" - "$linemsg"`"
head -n "$linelast" "$path" | \
tail -n "$linecount" | \
tr ' \t' ' ' | \
egrep '^ *m\.[A-Za-z_][A-Za-z0-9_]* *=' | \
sed 's/^ *m\.\([A-Za-z_][A-Za-z0-9_]*\) *=.*/IDENT('$callname', \1)/'
fi
pathprev="$path"
linemsgprev="$linemsg"
done
) | sort | uniq

17
kernel/extract-mtype.sh Normal file
View file

@ -0,0 +1,17 @@
#!/bin/sh
set -e
# grep message type constants and make them into a .h file
(
cat ../include/minix/callnr.h | \
tr -s ' \t' ' ' | \
sed 's/^# /#/' | \
egrep '^#define [A-Z_][A-Z0-9_]* [0-9]+' | grep -v NCALLS
cat ../include/minix/com.h | \
tr -s ' \t' ' ' | \
sed 's/^# /#/' | \
egrep '^#define [A-Z_][A-Z0-9_]* \( ?([A-Z0-9_]+_BASE|KERNEL_CALL) ?\+[A-Za-z0-9_ +]+\)'
) | cut -d' ' -f2 | sed 's/\(.*\)/IDENT(\1)/' | sort

View file

@ -560,6 +560,11 @@ PUBLIC int mini_send(
: (flags & NON_BLOCKING ? SENDNB : SEND));
IPC_STATUS_ADD_CALL(dst_ptr, call);
RTS_UNSET(dst_ptr, RTS_RECEIVING);
#if DEBUG_DUMPIPC
printmsgsend(&dst_ptr->p_delivermsg, caller_ptr, dst_ptr);
printmsgrecv(&dst_ptr->p_delivermsg, caller_ptr, dst_ptr);
#endif
} else {
if(flags & NON_BLOCKING) {
return(ENOTREADY);
@ -592,6 +597,10 @@ PUBLIC int mini_send(
xpp = &dst_ptr->p_caller_q; /* find end of list */
while (*xpp) xpp = &(*xpp)->p_q_link;
*xpp = caller_ptr; /* add caller to end */
#if DEBUG_DUMPIPC
printmsgsend(&caller_ptr->p_sendmsg, caller_ptr, dst_ptr);
#endif
}
return(OK);
}
@ -718,6 +727,10 @@ PRIVATE int mini_receive(struct proc * caller_ptr,
if (sender->p_misc_flags & MF_SIG_DELAY)
sig_delay_done(sender);
#if DEBUG_DUMPIPC
printmsgrecv(&caller_ptr->p_delivermsg, *xpp, caller_ptr);
#endif
*xpp = sender->p_q_link; /* remove from queue */
sender->p_q_link = NULL;
return(OK); /* report success */

View file

@ -101,6 +101,14 @@ _PROTOTYPE( char *schedulerstr, (struct proc *scheduler) );
_PROTOTYPE( void print_proc, (struct proc *pp));
/* prints the given process and recursively all processes it depends on */
_PROTOTYPE( void print_proc_recursive, (struct proc *pp));
#if DEBUG_DUMPIPC
_PROTOTYPE( void printmsgrecv, (message *msg, struct proc *src,
struct proc *dst) );
_PROTOTYPE( void printmsgsend, (message *msg, struct proc *src,
struct proc *dst) );
_PROTOTYPE( void printmsgkcall, (message *msg, struct proc *proc) );
_PROTOTYPE( void printmsgkresult, (message *msg, struct proc *proc) );
#endif
/* system/do_safemap.c */
_PROTOTYPE( int map_invoke_vm, (struct proc * caller, int req_type,

View file

@ -76,6 +76,9 @@ PRIVATE void kernel_call_finish(struct proc * caller, message *msg, int result)
/* copy the result as a message to the original user buffer */
msg->m_source = SYSTEM;
msg->m_type = result; /* report status of call */
#if DEBUG_DUMPIPC
printmsgkresult(msg, caller);
#endif
if (copy_msg_to_user(caller, msg,
(message *)caller->p_delivermsg_vir)) {
printf("WARNING wrong user pointer 0x%08x from "
@ -92,7 +95,10 @@ PRIVATE int kernel_call_dispatch(struct proc * caller, message *msg)
{
int result = OK;
int call_nr;
#if DEBUG_DUMPIPC
printmsgkcall(msg, caller);
#endif
call_nr = msg->m_type - KERNEL_CALL;
/* See if the caller made a valid request and try to handle it. */