April 2008 - launchd-changes - lists.macosforge.org

[23594] trunk/launchd/src/launchd_core_logic.c
by source_changes＠macosforge.org 08 Apr '08

08 Apr '08

Revision: 23594 http://trac.macosforge.org/projects/launchd/changeset/23594 Author: zarzycki(a)apple.com Date: 2008-04-08 13:38:15 -0700 (Tue, 08 Apr 2008) Log Message: ----------- Better logging at shutdown. Modified Paths: -------------- trunk/launchd/src/launchd_core_logic.c Modified: trunk/launchd/src/launchd_core_logic.c =================================================================== --- trunk/launchd/src/launchd_core_logic.c 2008-04-08 20:37:28 UTC (rev 23593) +++ trunk/launchd/src/launchd_core_logic.c 2008-04-08 20:38:15 UTC (rev 23594) @@ -308,6 +308,7 @@ static bool jobmgr_label_test(jobmgr_t jm, const char *str); static void jobmgr_reap_bulk(jobmgr_t jm, struct kevent *kev); static void jobmgr_log_stray_children(jobmgr_t jm); +static void jobmgr_kill_stray_child(jobmgr_t jm, pid_t p); static void jobmgr_remove(jobmgr_t jm); static void jobmgr_dispatch_all(jobmgr_t jm, bool newmounthack); static job_t jobmgr_init_session(jobmgr_t jm, const char *session_type, bool sflag); @@ -595,6 +596,8 @@ if (j->exit_timeout) { job_assumes(j, kevent_mod((uintptr_t)&j->exit_timeout, EVFILT_TIMER, EV_ADD|EV_ONESHOT, NOTE_SECONDS, j->exit_timeout, j) != -1); + } else { + job_log(j, LOG_DEBUG, "This job has an infinite exit timeout"); } if (j->kill_via_shmem) { @@ -2193,11 +2196,9 @@ size_t i, kp_cnt, len = sizeof(struct kinfo_proc) * get_kern_max_proc(); struct kinfo_proc *kp; -#if TARGET_OS_EMBEDDED if (!do_apple_internal_logging) { return; } -#endif runtime_ktrace(RTKT_LAUNCHD_FINDING_STRAY_PG, j->p, 0, 0); @@ -3063,11 +3064,10 @@ struct kinfo_proc *kp; uid_t u = j->mach_uid; -#if TARGET_OS_EMBEDDED if (!do_apple_internal_logging) { return; } -#endif + kp = malloc(len); if (!job_assumes(j, kp != NULL)) { @@ -4629,17 +4629,59 @@ } void +jobmgr_kill_stray_child(jobmgr_t jm, pid_t p) +{ + struct timespec ts = { 2, 0 }; + uint64_t start, end, nanosec; + struct kevent kev; + int r, kq = kqueue(); + + if (!jobmgr_assumes(jm, kq != -1)) { + return; + } + + EV_SET(&kev, p, EVFILT_PROC, EV_ADD, 0, 0, 0); + + if (!jobmgr_assumes(jm, kevent(kq, &kev, 1, NULL, 0, NULL) != -1)) { + goto out; + } + + start = runtime_get_opaque_time(); + + if (!jobmgr_assumes(jm, runtime_kill(p, SIGTERM) != -1)) { + goto out; + } + + r = kevent(kq, NULL, 0, &kev, 1, &ts); + + if (!jobmgr_assumes(jm, r == 0 || r == 1)) { + goto out; + } + + if (r == 0 && jobmgr_assumes(jm, runtime_kill(p, SIGKILL) != -1)) { + jobmgr_assumes(jm, kevent(kq, NULL, 0, &kev, 1, NULL) == 1); + } + + end = runtime_get_opaque_time(); + + nanosec = runtime_opaque_time_to_nano(end - start); + + jobmgr_log(jm, LOG_DEBUG, "PID %u died after %llu nanoseconds", p, nanosec); + +out: + jobmgr_assumes(jm, runtime_close(kq) != -1); +} + +void jobmgr_log_stray_children(jobmgr_t jm) { int mib[] = { CTL_KERN, KERN_PROC, KERN_PROC_ALL }; size_t i, kp_cnt = 0, kp_skipped = 0, len = sizeof(struct kinfo_proc) * get_kern_max_proc(); struct kinfo_proc *kp; -#if TARGET_OS_EMBEDDED if (!do_apple_internal_logging) { return; } -#endif if (likely(jm->parentmgr || !pid1_magic)) { return; @@ -4671,10 +4713,7 @@ jobmgr_log(jm, LOG_WARNING, "Stray %sprocess at shutdown: PID %u PPID %u PGID %u %s", z, p_i, pp_i, pg_i, n); - /* - * The kernel team requested that launchd not do this for Leopard. - * jobmgr_assumes(jm, runtime_kill(p_i, SIGKILL) != -1); - */ + jobmgr_kill_stray_child(jm, p_i); } out:

1 0

[23593] trunk/launchd/src
by source_changes＠macosforge.org 08 Apr '08

08 Apr '08

Revision: 23593 http://trac.macosforge.org/projects/launchd/changeset/23593 Author: zarzycki(a)apple.com Date: 2008-04-08 13:37:28 -0700 (Tue, 08 Apr 2008) Log Message: ----------- <rdar://problem/5849623> Workaround 5225889 consistently Modified Paths: -------------- trunk/launchd/src/launchd_core_logic.c trunk/launchd/src/launchd_runtime.c Modified: trunk/launchd/src/launchd_core_logic.c =================================================================== --- trunk/launchd/src/launchd_core_logic.c 2008-04-08 16:37:06 UTC (rev 23592) +++ trunk/launchd/src/launchd_core_logic.c 2008-04-08 20:37:28 UTC (rev 23593) @@ -3447,9 +3447,6 @@ head_later = LIST_FIRST(&sorted_calendar_events)->when_next; - /* Workaround 5225889 */ - kevent_mod((uintptr_t)&sorted_calendar_events, EVFILT_TIMER, EV_DELETE, 0, 0, root_jobmgr); - if (job_assumes(j, kevent_mod((uintptr_t)&sorted_calendar_events, EVFILT_TIMER, EV_ADD, NOTE_ABSOLUTE|NOTE_SECONDS, head_later, root_jobmgr) != -1)) { char time_string[100]; size_t time_string_len; @@ -5867,9 +5864,6 @@ } else if (inval) { if (j->start_interval == 0) { runtime_add_weak_ref(); - } else { - /* Workaround 5225889 */ - job_assumes(j, kevent_mod((uintptr_t)&j->start_interval, EVFILT_TIMER, EV_DELETE, 0, 0, j) != -1); } j->start_interval = inval; job_assumes(j, kevent_mod((uintptr_t)&j->start_interval, EVFILT_TIMER, EV_ADD, NOTE_SECONDS, j->start_interval, j) != -1); Modified: trunk/launchd/src/launchd_runtime.c =================================================================== --- trunk/launchd/src/launchd_runtime.c 2008-04-08 16:37:06 UTC (rev 23592) +++ trunk/launchd/src/launchd_runtime.c 2008-04-08 20:37:28 UTC (rev 23593) @@ -840,6 +840,12 @@ case EVFILT_READ: case EVFILT_WRITE: break; + case EVFILT_TIMER: + /* Workaround 5225889 */ + if (flags & EV_ADD) { + kevent_mod(ident, EVFILT_TIMER, EV_DELETE, 0, 0, NULL); + } + /* fall through */ default: flags |= EV_CLEAR; break;

1 0

[23592] trunk/launchd/src/launchd_core_logic.c
by source_changes＠macosforge.org 08 Apr '08

08 Apr '08

Revision: 23592 http://trac.macosforge.org/projects/launchd/changeset/23592 Author: zarzycki(a)apple.com Date: 2008-04-08 09:37:06 -0700 (Tue, 08 Apr 2008) Log Message: ----------- A small text change. Modified Paths: -------------- trunk/launchd/src/launchd_core_logic.c Modified: trunk/launchd/src/launchd_core_logic.c =================================================================== --- trunk/launchd/src/launchd_core_logic.c 2008-04-03 21:10:08 UTC (rev 23591) +++ trunk/launchd/src/launchd_core_logic.c 2008-04-08 16:37:06 UTC (rev 23592) @@ -2507,7 +2507,7 @@ job_assumes(j, kevent_mod((uintptr_t)&j->exit_timeout, EVFILT_TIMER, EV_ADD, NOTE_SECONDS, LAUNCHD_SIGKILL_TIMER, j) != -1); - job_log(j, LOG_DEBUG, "Sent SIGKILL signal."); + job_log(j, LOG_DEBUG, "Sent SIGKILL signal"); } void

1 0

[23591] tags/launchd-269/
by source_changes＠macosforge.org 03 Apr '08

03 Apr '08

Revision: 23591 http://trac.macosforge.org/projects/launchd/changeset/23591 Author: zarzycki(a)apple.com Date: 2008-04-03 14:10:08 -0700 (Thu, 03 Apr 2008) Log Message: ----------- "Tagging launchd-269 from https://svn.macosforge.org/repository/launchd/trunk" Added Paths: ----------- tags/launchd-269/ Copied: tags/launchd-269 (from rev 23590, trunk)

1 0

[23590] trunk/launchd/src
by source_changes＠macosforge.org 03 Apr '08

03 Apr '08

Revision: 23590 http://trac.macosforge.org/projects/launchd/changeset/23590 Author: zarzycki(a)apple.com Date: 2008-04-03 10:39:19 -0700 (Thu, 03 Apr 2008) Log Message: ----------- Move _vproc_logv() from internal API to private API. Modified Paths: -------------- trunk/launchd/src/libvproc_internal.h trunk/launchd/src/libvproc_private.h Modified: trunk/launchd/src/libvproc_internal.h =================================================================== --- trunk/launchd/src/libvproc_internal.h 2008-04-02 20:57:44 UTC (rev 23589) +++ trunk/launchd/src/libvproc_internal.h 2008-04-03 17:39:19 UTC (rev 23590) @@ -99,7 +99,6 @@ }; -void _vproc_logv(int pri, int err, const char *msg, va_list ap); vproc_err_t _vprocmgr_log_forward(mach_port_t mp, void *data, size_t len); Modified: trunk/launchd/src/libvproc_private.h =================================================================== --- trunk/launchd/src/libvproc_private.h 2008-04-02 20:57:44 UTC (rev 23589) +++ trunk/launchd/src/libvproc_private.h 2008-04-03 17:39:19 UTC (rev 23590) @@ -67,6 +67,7 @@ void _vproc_log(int pri, const char *msg, ...) __attribute__((format(printf, 2, 3))); void _vproc_log_error(int pri, const char *msg, ...) __attribute__((format(printf, 2, 3))); +void _vproc_logv(int pri, int err, const char *msg, va_list ap) __attribute__((format(printf, 3, 0))); #define VPROCMGR_SESSION_LOGINWINDOW "LoginWindow" #define VPROCMGR_SESSION_BACKGROUND "Background"

1 0

[23589] trunk/launchd/src
by source_changes＠macosforge.org 02 Apr '08

02 Apr '08

Revision: 23589 http://trac.macosforge.org/projects/launchd/changeset/23589 Author: zarzycki(a)apple.com Date: 2008-04-02 13:57:44 -0700 (Wed, 02 Apr 2008) Log Message: ----------- <rdar://problem/5834789> Observably inaccurate logging during shutdown (exit duration) Modified Paths: -------------- trunk/launchd/src/launchd_core_logic.c trunk/launchd/src/launchd_runtime.c trunk/launchd/src/launchd_runtime.h Modified: trunk/launchd/src/launchd_core_logic.c =================================================================== --- trunk/launchd/src/launchd_core_logic.c 2008-04-02 20:26:26 UTC (rev 23588) +++ trunk/launchd/src/launchd_core_logic.c 2008-04-02 20:57:44 UTC (rev 23589) @@ -2326,13 +2326,12 @@ } if (j->sent_sigterm_time) { - uint64_t td_sec, td_usec, td = runtime_opaque_time_to_nano(runtime_get_opaque_time() - j->sent_sigterm_time); + uint64_t td_sec, td_usec, td = runtime_get_nanoseconds_since(j->sent_sigterm_time); td_sec = td / NSEC_PER_SEC; td_usec = (td % NSEC_PER_SEC) / NSEC_PER_USEC; - job_log(j, LOG_INFO, "Exited %lld.%06lld seconds after %s was sent", - td_sec, td_usec, signal_to_C_name(j->sent_sigkill ? SIGKILL : SIGTERM)); + job_log(j, LOG_INFO, "Exited %lld.%06lld seconds after %s was sent", td_sec, td_usec, signal_to_C_name(SIGTERM)); } #if DO_RUSAGE_SUMMATION @@ -2620,7 +2619,7 @@ job_dispatch(j, false); } else if (&j->exit_timeout == ident) { if (j->sent_sigkill) { - uint64_t td = runtime_opaque_time_to_nano(runtime_get_opaque_time() - j->sent_sigterm_time); + uint64_t td = runtime_get_nanoseconds_since(j->sent_sigterm_time); td /= NSEC_PER_SEC; td -= j->exit_timeout; @@ -2752,7 +2751,7 @@ void job_start(job_t j) { - uint64_t td, tnow = runtime_get_opaque_time(); + uint64_t td; int spair[2]; int execspair[2]; int oepair[2]; @@ -2770,14 +2769,12 @@ return; } - job_assumes(j, tnow > j->start_time); - /* * Some users adjust the wall-clock and then expect software to not notice. * Therefore, launchd must use an absolute clock instead of the wall clock * wherever possible. */ - td = runtime_opaque_time_to_nano(tnow - j->start_time); + td = runtime_get_nanoseconds_since(j->start_time); td /= NSEC_PER_SEC; if (j->start_time && (td < j->min_run_time) && !j->legacy_mach_job && !j->inetcompat) { @@ -2814,8 +2811,6 @@ job_assumes(j, kevent_mod(j->log_redirect_fd, EVFILT_READ, EV_ADD, 0, 0, j) != -1); } - j->start_time = tnow; - switch (c = runtime_fork(j->weird_bootstrap ? j->j_port : j->mgr->jm_port)) { case -1: job_log_error(j, LOG_ERR, "fork() failed, will try again in one second"); @@ -2852,6 +2847,8 @@ job_start_child(j); break; default: + j->start_time = runtime_get_opaque_time(); + job_log(j, LOG_DEBUG, "Started as PID: %u", c); j->start_pending = false; Modified: trunk/launchd/src/launchd_runtime.c =================================================================== --- trunk/launchd/src/launchd_runtime.c 2008-04-02 20:26:26 UTC (rev 23588) +++ trunk/launchd/src/launchd_runtime.c 2008-04-02 20:57:44 UTC (rev 23589) @@ -117,6 +117,7 @@ static void do_file_init(void) __attribute__((constructor)); static mach_timebase_info_data_t tbi; static uint64_t tbi_safe_math_max; +static uint64_t time_of_mach_msg_return; static double tbi_float_val; static const int sigigns[] = { SIGHUP, SIGINT, SIGPIPE, SIGALRM, SIGTERM, @@ -1025,6 +1026,8 @@ mr = mach_msg(&bufReply->Head, tmp_options, bufReply->Head.msgh_size, msg_size, ipc_port_set, to, MACH_PORT_NULL); + time_of_mach_msg_return = runtime_get_opaque_time(); + tmp_options = options; /* It looks like the compiler doesn't optimize switch(unlikely(...)) */ @@ -1639,11 +1642,23 @@ } INTERNAL_ABI uint64_t +runtime_get_opaque_time_of_event(void) +{ + return time_of_mach_msg_return; +} + +INTERNAL_ABI uint64_t +runtime_get_nanoseconds_since(uint64_t o) +{ + return runtime_opaque_time_to_nano(runtime_get_opaque_time_of_event() - o); +} + +INTERNAL_ABI uint64_t runtime_opaque_time_to_nano(uint64_t o) { -#if defined(__i386__) +#if defined(__i386__) || defined(__x86_64__) if (unlikely(tbi.numer != tbi.denom)) { -#elif defined(__ppc__) +#elif defined(__ppc__) || defined(__ppc64__) if (likely(tbi.numer != tbi.denom)) { #else if (tbi.numer != tbi.denom) { Modified: trunk/launchd/src/launchd_runtime.h =================================================================== --- trunk/launchd/src/launchd_runtime.h 2008-04-02 20:26:26 UTC (rev 23588) +++ trunk/launchd/src/launchd_runtime.h 2008-04-02 20:57:44 UTC (rev 23589) @@ -187,9 +187,11 @@ INTERNAL_ABI void runtime_vsyslog(struct runtime_syslog_attr *attr, const char *message, va_list args) __attribute__((format(printf, 2, 0))); INTERNAL_ABI void runtime_log_push(void); -INTERNAL_ABI int64_t runtime_get_wall_time(void); -INTERNAL_ABI uint64_t runtime_get_opaque_time(void); -INTERNAL_ABI uint64_t runtime_opaque_time_to_nano(uint64_t o); +INTERNAL_ABI int64_t runtime_get_wall_time(void) __attribute__((warn_unused_result)); +INTERNAL_ABI uint64_t runtime_get_opaque_time(void) __attribute__((warn_unused_result)); +INTERNAL_ABI uint64_t runtime_get_opaque_time_of_event(void) __attribute__((pure, warn_unused_result)); +INTERNAL_ABI uint64_t runtime_opaque_time_to_nano(uint64_t o) __attribute__((const, warn_unused_result)); +INTERNAL_ABI uint64_t runtime_get_nanoseconds_since(uint64_t o) __attribute__((pure, warn_unused_result)); INTERNAL_ABI kern_return_t launchd_set_bport(mach_port_t name); INTERNAL_ABI kern_return_t launchd_get_bport(mach_port_t *name);

1 0

[23588] tags/launchd-268/
by source_changes＠macosforge.org 02 Apr '08

02 Apr '08

Revision: 23588 http://trac.macosforge.org/projects/launchd/changeset/23588 Author: zarzycki(a)apple.com Date: 2008-04-02 13:26:26 -0700 (Wed, 02 Apr 2008) Log Message: ----------- "Tagging launchd-268 from https://svn.macosforge.org/repository/launchd/trunk" Added Paths: ----------- tags/launchd-268/ Copied: tags/launchd-268 (from rev 23587, trunk)

1 0

[23587] tags/launchd-258.12/
by source_changes＠macosforge.org 02 Apr '08

02 Apr '08

Revision: 23587 http://trac.macosforge.org/projects/launchd/changeset/23587 Author: zarzycki(a)apple.com Date: 2008-04-02 13:23:40 -0700 (Wed, 02 Apr 2008) Log Message: ----------- "Tagging launchd-258.12 from https://svn.macosforge.org/repository/launchd/branches/SULeopard" Added Paths: ----------- tags/launchd-258.12/ Copied: tags/launchd-258.12 (from rev 23586, branches/SULeopard)

1 0

[23586] trunk/launchd/src/launchd_core_logic.c
by source_changes＠macosforge.org 02 Apr '08

02 Apr '08

Revision: 23586 http://trac.macosforge.org/projects/launchd/changeset/23586 Author: zarzycki(a)apple.com Date: 2008-04-02 13:22:03 -0700 (Wed, 02 Apr 2008) Log Message: ----------- <rdar://problem/5835375> 10.5.3 Regression: Failure to shutdown in 9D11 with zombie shutdown Modified Paths: -------------- trunk/launchd/src/launchd_core_logic.c Modified: trunk/launchd/src/launchd_core_logic.c =================================================================== --- trunk/launchd/src/launchd_core_logic.c 2008-04-02 20:18:49 UTC (rev 23585) +++ trunk/launchd/src/launchd_core_logic.c 2008-04-02 20:22:03 UTC (rev 23586) @@ -4175,7 +4175,7 @@ } else if (j->removal_pending) { job_log(j, LOG_DEBUG, "Exited while removal was pending."); return true; - } else if (j->mgr->shutting_down && j->mgr->hopefully_first_cnt == 0) { + } else if (j->mgr->shutting_down && (j->hopefully_exits_first || j->mgr->hopefully_first_cnt == 0)) { job_log(j, LOG_DEBUG, "Exited while shutdown in progress. Processes remaining: %lu/%lu", total_children, total_anon_children); return true; } else if (j->legacy_mach_job) { @@ -4202,13 +4202,17 @@ bool good_exit = (WIFEXITED(j->last_exit_status) && WEXITSTATUS(j->last_exit_status) == 0); bool is_not_kextd = (do_apple_internal_logging || (strcmp(j->label, "com.apple.kextd") != 0)); + if (unlikely(j->mgr->shutting_down)) { + return false; + } + /* * 5066316 * * We definitely need to revisit this after Leopard ships. Please see * launchctl.c for the other half of this hack. */ - if (unlikely((j->mgr->shutting_down || j->mgr->global_on_demand_cnt > 0) && is_not_kextd)) { + if (unlikely((j->mgr->global_on_demand_cnt > 0) && is_not_kextd)) { return false; }

1 0

[23585] branches/SULeopard/launchd/src/launchd_core_logic.c
by source_changes＠macosforge.org 02 Apr '08

02 Apr '08

Revision: 23585 http://trac.macosforge.org/projects/launchd/changeset/23585 Author: zarzycki(a)apple.com Date: 2008-04-02 13:18:49 -0700 (Wed, 02 Apr 2008) Log Message: ----------- <rdar://problem/5835375> 10.5.3 Regression: Failure to shutdown in 9D11 with zombie shutdown Modified Paths: -------------- branches/SULeopard/launchd/src/launchd_core_logic.c Modified: branches/SULeopard/launchd/src/launchd_core_logic.c =================================================================== --- branches/SULeopard/launchd/src/launchd_core_logic.c 2008-04-02 17:48:25 UTC (rev 23584) +++ branches/SULeopard/launchd/src/launchd_core_logic.c 2008-04-02 20:18:49 UTC (rev 23585) @@ -3884,7 +3884,7 @@ } else if (j->removal_pending) { job_log(j, LOG_DEBUG, "Exited while removal was pending."); return true; - } else if (j->mgr->shutting_down && j->mgr->hopefully_first_cnt == 0) { + } else if (j->mgr->shutting_down && (j->hopefully_exits_first || j->mgr->hopefully_first_cnt == 0)) { job_log(j, LOG_DEBUG, "Exited while shutdown in progress. Processes remaining: %lu/%lu", total_children, total_anon_children); return true; } else if (j->legacy_mach_job) { @@ -3910,13 +3910,17 @@ struct stat sb; bool good_exit = (WIFEXITED(j->last_exit_status) && WEXITSTATUS(j->last_exit_status) == 0); + if (j->mgr->shutting_down) { + return false; + } + /* * 5066316 * * We definitely need to revisit this after Leopard ships. Please see * launchctl.c for the other half of this hack. */ - if ((j->mgr->shutting_down || j->mgr->global_on_demand_cnt > 0) && strcmp(j->label, "com.apple.kextd") != 0) { + if (j->mgr->global_on_demand_cnt > 0 && strcmp(j->label, "com.apple.kextd") != 0) { return false; }

1 0