Revision: 23490 http://trac.macosforge.org/projects/launchd/changeset/23490 Author: zarzycki@apple.com Date: 2008-01-21 14:14:27 -0800 (Mon, 21 Jan 2008) Log Message: ----------- Kernel trace logic support. Modified Paths: -------------- trunk/launchd/src/launchd.c trunk/launchd/src/launchd_core_logic.c trunk/launchd/src/launchd_runtime.c trunk/launchd/src/launchd_runtime.h Modified: trunk/launchd/src/launchd.c =================================================================== --- trunk/launchd/src/launchd.c 2008-01-19 00:53:23 UTC (rev 23489) +++ trunk/launchd/src/launchd.c 2008-01-21 22:14:27 UTC (rev 23490) @@ -243,6 +243,8 @@ return; } + runtime_ktrace0(RTKT_LAUNCHD_EXITING); + shutdown_in_progress = true; if (pid1_magic) { @@ -391,6 +393,8 @@ const char *file = strrchr(path, '/'); char *rcs_rev_tmp = strchr(rcs_rev, ' '); + runtime_ktrace1(RTKT_LAUNCHD_BUG); + if (!file) { file = path; } else { Modified: trunk/launchd/src/launchd_core_logic.c =================================================================== --- trunk/launchd/src/launchd_core_logic.c 2008-01-19 00:53:23 UTC (rev 23489) +++ trunk/launchd/src/launchd_core_logic.c 2008-01-21 22:14:27 UTC (rev 23490) @@ -2083,6 +2083,8 @@ size_t i, kp_cnt, len = 10*1024*1024; struct kinfo_proc *kp; + runtime_ktrace(RTKT_LAUNCHD_FINDING_STRAY_PG, j->p, 0, 0); + if (!job_assumes(j, (kp = malloc(len)) != NULL)) { return; } @@ -2925,6 +2927,9 @@ if (!job_assumes(j, kp != NULL)) { return; } + + runtime_ktrace(RTKT_LAUNCHD_FINDING_WEIRD_UIDS, j->p, u, 0); + if (!job_assumes(j, sysctl(mib, 3, kp, &len, NULL, 0) != -1)) { goto out; } @@ -3266,6 +3271,8 @@ int saved_errno = errno; char buf[100]; + runtime_ktrace1(RTKT_LAUNCHD_BUG); + extract_rcsid_substr(__rcs_file_version__, buf, sizeof(buf)); if (!file) { @@ -3292,6 +3299,8 @@ int saved_errno = errno; char buf[100]; + runtime_ktrace1(RTKT_LAUNCHD_BUG); + extract_rcsid_substr(__rcs_file_version__, buf, sizeof(buf)); if (!file) { @@ -4421,6 +4430,9 @@ if (!jobmgr_assumes(jm, (kp = malloc(len)) != NULL)) { return; } + + runtime_ktrace0(RTKT_LAUNCHD_FINDING_ALL_STRAYS); + if (!jobmgr_assumes(jm, sysctl(mib, 3, kp, &len, NULL, 0) != -1)) { goto out; } @@ -5432,6 +5444,7 @@ return 1; } + runtime_ktrace0(RTKT_LAUNCHD_DATA_UNPACK); if (unlikely(invalCnt && !job_assumes(j, (input_obj = launch_data_unpack((void *)inval, invalCnt, NULL, 0, &data_offset, NULL)) != NULL))) { goto out_bad; } @@ -5442,6 +5455,7 @@ goto out_bad; } jobmgr_export_env_from_other_jobs(j->mgr, output_obj); + runtime_ktrace0(RTKT_LAUNCHD_DATA_PACK); if (!job_assumes(j, launch_data_pack(output_obj, (void *)*outval, *outvalCnt, NULL, NULL) != 0)) { goto out_bad; } @@ -5452,6 +5466,7 @@ goto out_bad; } ipc_revoke_fds(output_obj); + runtime_ktrace0(RTKT_LAUNCHD_DATA_PACK); packed_size = launch_data_pack(output_obj, (void *)*outval, *outvalCnt, NULL, NULL); if (!job_assumes(j, packed_size != 0)) { goto out_bad; @@ -6415,6 +6430,7 @@ job_assumes(j, cnt == cnt2); + runtime_ktrace0(RTKT_LAUNCHD_DATA_PACK); packed_size = launch_data_pack(outdata_obj_array, (void *)*outdata, *outdataCnt, NULL, NULL); if (!job_assumes(j, packed_size != 0)) { goto out_bad; @@ -6671,6 +6687,7 @@ return 1; } + runtime_ktrace0(RTKT_LAUNCHD_DATA_UNPACK); if (!job_assumes(j, (input_obj = launch_data_unpack((void *)indata, indataCnt, NULL, 0, &data_offset, NULL)) != NULL)) { return 1; } Modified: trunk/launchd/src/launchd_runtime.c =================================================================== --- trunk/launchd/src/launchd_runtime.c 2008-01-19 00:53:23 UTC (rev 23489) +++ trunk/launchd/src/launchd_runtime.c 2008-01-21 22:14:27 UTC (rev 23490) @@ -45,6 +45,7 @@ #include <sys/mount.h> #include <sys/reboot.h> #include <sys/fcntl.h> +#include <sys/kdebug.h> #include <bsm/libbsm.h> #include <malloc/malloc.h> #include <unistd.h> @@ -86,7 +87,7 @@ static void *mport_demand_loop(void *arg); static void *kqueue_demand_loop(void *arg); -static void log_kevent_struct(int level, struct kevent *kev, int indx); +static void log_kevent_struct(int level, struct kevent *kev_base, int indx); static boolean_t launchd_internal_demux(mach_msg_header_t *Request, mach_msg_header_t *Reply); static void record_caller_creds(mach_msg_header_t *mh); @@ -347,8 +348,9 @@ } void -log_kevent_struct(int level, struct kevent *kev, int indx) +log_kevent_struct(int level, struct kevent *kev_base, int indx) { + struct kevent *kev = &kev_base[indx]; const char *filter_str; char ident_buf[100]; char filter_buf[100]; @@ -547,7 +549,7 @@ (*((kq_callback *)kev.udata))(kev.udata, &kev); #if 0 } else { - log_kevent_struct(LOG_ERR, &kev); + log_kevent_struct(LOG_ERR, &kev, 0); } #endif /* the callback may have tainted our ability to continue this for loop */ @@ -601,17 +603,19 @@ if (launchd_assumes(malloc_size(kev.udata) || dladdr(kev.udata, &dli))) { #endif for (i = 0; i < bulk_kev_cnt; i++) { - log_kevent_struct(LOG_DEBUG, &kev[i], i); + log_kevent_struct(LOG_DEBUG, kev, i); } for (i = 0; i < bulk_kev_cnt; i++) { bulk_kev_i = i; if (kev[i].filter) { + runtime_ktrace(RTKT_LAUNCHD_BSD_KEVENT|DBG_FUNC_START, kev[i].ident, kev[i].filter, kev[i].fflags); (*((kq_callback *)kev[i].udata))(kev[i].udata, &kev[i]); + runtime_ktrace0(RTKT_LAUNCHD_BSD_KEVENT|DBG_FUNC_END); } } #if 0 } else { - log_kevent_struct(LOG_ERR, &kev); + log_kevent_struct(LOG_ERR, &kev, 0); } #endif } @@ -1072,6 +1076,8 @@ no_hang_fd = _fd(open("/dev/autofs_nowait", 0)); } + runtime_ktrace(RTKT_LAUNCHD_MACH_IPC|DBG_FUNC_START, bufRequest->Head.msgh_local_port, bufRequest->Head.msgh_id, (int)the_demux); + if (the_demux(&bufRequest->Head, &bufReply->Head) == FALSE) { /* XXX - also gross */ if (likely(bufRequest->Head.msgh_id == MACH_NOTIFY_NO_SENDERS)) { @@ -1079,6 +1085,8 @@ } } + runtime_ktrace(RTKT_LAUNCHD_MACH_IPC|DBG_FUNC_END, bufReply->Head.msgh_remote_port, bufReply->Head.msgh_bits, bufReply->RetCode); + /* bufReply is a union. If MACH_MSGH_BITS_COMPLEX is set, then bufReply->RetCode is assumed to be zero. */ if (!(bufReply->Head.msgh_bits & MACH_MSGH_BITS_COMPLEX)) { if (unlikely(bufReply->RetCode != KERN_SUCCESS)) { @@ -1099,6 +1107,7 @@ tmp_options |= MACH_SEND_TIMEOUT; } } + } } @@ -1309,16 +1318,40 @@ mig_deallocate(outval, outvalCnt); } -#if 0 -void -runtime_kernel_trace(void *code, void *a, void *b, void *c, void *d) +INTERNAL_ABI void +runtime_ktrace1(runtime_ktrace_code_t code) { - /* Request codes from Joe S. */ - syscall(180 , code, a, b, c, d); + void *ra = __builtin_extract_return_addr(__builtin_return_address(1)); + + /* This syscall returns EINVAL when the trace isn't enabled. */ + if (do_apple_internal_logging) { + syscall(180, code, 0, 0, 0, (int)ra); + } } -#endif INTERNAL_ABI void +runtime_ktrace0(runtime_ktrace_code_t code) +{ + void *ra = __builtin_extract_return_addr(__builtin_return_address(0)); + + /* This syscall returns EINVAL when the trace isn't enabled. */ + if (do_apple_internal_logging) { + syscall(180, code, 0, 0, 0, (int)ra); + } +} + +INTERNAL_ABI void +runtime_ktrace(runtime_ktrace_code_t code, int a, int b, int c) +{ + void *ra = __builtin_extract_return_addr(__builtin_return_address(0)); + + /* This syscall returns EINVAL when the trace isn't enabled. */ + if (do_apple_internal_logging) { + syscall(180, code, a, b, c, (int)ra); + } +} + +INTERNAL_ABI void runtime_log_push(void) { static pthread_mutex_t ourlock = PTHREAD_MUTEX_INITIALIZER; Modified: trunk/launchd/src/launchd_runtime.h =================================================================== --- trunk/launchd/src/launchd_runtime.h 2008-01-19 00:53:23 UTC (rev 23489) +++ trunk/launchd/src/launchd_runtime.h 2008-01-21 22:14:27 UTC (rev 23490) @@ -139,6 +139,33 @@ INTERNAL_ABI kern_return_t runtime_log_forward(uid_t forward_uid, gid_t forward_gid, vm_offset_t inval, mach_msg_type_number_t invalCnt); INTERNAL_ABI kern_return_t runtime_log_drain(mach_port_t srp, vm_offset_t *outval, mach_msg_type_number_t *outvalCnt); +#ifndef DBG_LAUNCHD +#define DBG_LAUNCHD 34 +#endif + +/* Class(8) | SubClass(8) | Code(14) | Qual(2) */ +#define RTKT_CODE(c) ((DBG_LAUNCHD << 24) | (((c) & 0x3fffff) << 2)) + +typedef enum { + RTKT_LAUNCHD_STARTING = RTKT_CODE(1), + RTKT_LAUNCHD_EXITING = RTKT_CODE(2), + RTKT_LAUNCHD_FINDING_STRAY_PG = RTKT_CODE(3), + RTKT_LAUNCHD_FINDING_ALL_STRAYS = RTKT_CODE(4), + RTKT_LAUNCHD_FINDING_EXECLESS = RTKT_CODE(5), + RTKT_LAUNCHD_FINDING_WEIRD_UIDS = RTKT_CODE(6), + RTKT_LAUNCHD_DATA_PACK = RTKT_CODE(7), + RTKT_LAUNCHD_DATA_UNPACK = RTKT_CODE(8), + RTKT_LAUNCHD_BUG = RTKT_CODE(9), + RTKT_LAUNCHD_MACH_IPC = RTKT_CODE(10), + RTKT_LAUNCHD_BSD_KEVENT = RTKT_CODE(11), +} runtime_ktrace_code_t; + +/* All of these log the return address as "arg4" */ +INTERNAL_ABI void runtime_ktrace1(runtime_ktrace_code_t code); +INTERNAL_ABI void runtime_ktrace0(runtime_ktrace_code_t code); +INTERNAL_ABI void runtime_ktrace(runtime_ktrace_code_t code, int a, int b, int c); + + #define LOG_APPLEONLY 0x4141504c /* AAPL in hex */ struct runtime_syslog_attr {