diff --git a/src/pmie/src/act.sk b/src/pmie/src/act.sk index 1aa3203..d87a2af 100644 --- a/src/pmie/src/act.sk +++ b/src/pmie/src/act.sk @@ -77,6 +77,7 @@ actShell(Expr *x) #ifdef IS_MINGW putenv("IFS=\t\n"); sts = system((char *)arg1->ring); + need_wait = 1; if (sts < 0) { __pmNotifyErr(LOG_ERR, "spawn for shell failed\n"); *(Truth *)x->ring = FALSE; @@ -230,6 +231,7 @@ actAlarm(Expr *x) _exit(1); /* avoid atexit() handler */ } else if (sts > 0) { + need_wait = 1; #if PCP_DEBUG if (pmDebug & DBG_TRACE_APPL2) { fprintf(stderr, "actAlarm: fork: pid=%d\n", sts); diff --git a/src/pmie/src/dstruct.c b/src/pmie/src/dstruct.c index 3572984..865cd49 100644 --- a/src/pmie/src/dstruct.c +++ b/src/pmie/src/dstruct.c @@ -113,6 +113,11 @@ static double month; /* month of the year 1..12 */ static double year; /* year 1996.. */ static double weekday; /* days since Sunday 0..6 */ +/*********************************************************************** + * process creation control + ***********************************************************************/ +int need_wait; + /* return real time */ RealTime @@ -185,62 +190,103 @@ unrealizenano(RealTime rt, struct timespec *ts) ts->tv_nsec = (int)(1000000000 * (rt - ts->tv_sec)); } +#define SLEEP_EVAL 0 +#define SLEEP_RETRY 1 -/* sleep until given RealTime */ +/* sleep until eval or retry RealTime */ void -sleepTight(RealTime sched) +sleepTight(Task *t, int type) { + RealTime sched; RealTime delay; /* interval to sleep */ int sts; + RealTime cur_entry = getReal(); #ifdef HAVE_WAITPID pid_t pid; - /* harvest terminated children */ - while ((pid = waitpid(-1, &sts, WNOHANG)) > (pid_t)0) { + if (need_wait) { + /* harvest terminated children */ + while ((pid = waitpid(-1, &sts, WNOHANG)) > (pid_t)0) { #if PCP_DEBUG - if (pmDebug & DBG_TRACE_APPL2) { - fprintf(stderr, "sleepTight: wait: pid=%d done status=0x%x", (int)pid, sts); - if (WIFEXITED(sts)) - fprintf(stderr, " exit=%d", WEXITSTATUS(sts)); - if (WIFSIGNALED(sts)) - fprintf(stderr, " signal=%d", WTERMSIG(sts)); - fprintf(stderr, "\n"); - } + if (pmDebug & DBG_TRACE_APPL2) { + fprintf(stderr, "sleepTight: wait: pid=%d done status=0x%x", (int)pid, sts); + if (WIFEXITED(sts)) + fprintf(stderr, " exit=%d", WEXITSTATUS(sts)); + if (WIFSIGNALED(sts)) + fprintf(stderr, " signal=%d", WTERMSIG(sts)); + fprintf(stderr, "\n"); + } #endif - ; + ; + } + need_wait = 0; } #endif if (!archives) { struct timespec ts, tleft; + static RealTime last_sched = -1; + static Task *last_t; + static int last_type; RealTime cur = getReal(); + sched = type == SLEEP_EVAL ? t->eval : t->retry; + delay = sched - cur; - if (delay <= -1) { - fprintf(stderr, "sleepTight: negative delay (%f). sched=%f, cur=%f\n", - delay, sched, cur); - } + if (delay < 0) { + int show_detail = 0; + if (delay <= -1) { + fprintf(stderr, "sleepTight: negative delay (%f). sched=%f, cur=%f\n", + delay, sched, cur); + show_detail = 1; + } #if PCP_DEBUG - if (pmDebug & DBG_TRACE_APPL2) { - if (delay < 0 && delay > -1) { - fprintf(stderr, "sleepTight: small negative delay (%f). sched=%f, cur=%f\n", + else { + if (pmDebug & DBG_TRACE_APPL2) { + fprintf(stderr, "sleepTight: small negative delay (%f). sched=%f, cur=%f\n", delay, sched, cur); + show_detail = 1; + } } - } #endif - - unrealizenano(delay, &ts); - for (;;) { /* loop to catch early wakeup from nanosleep */ - if (ts.tv_sec < 0 || ts.tv_nsec > 999999999) { - fprintf(stderr, "sleepTight: invalid args: %ld %ld\n", - ts.tv_sec, ts.tv_nsec); - break; + if (show_detail) { + if (last_sched > 0) { + fprintf(stderr, "Last sleepTight (%s) until: ", last_type == SLEEP_EVAL ? "eval" : "retry"); + showFullTime(stderr, last_sched); + fputc('\n', stderr); + fprintf(stderr, "Last "); + dumpTask(last_t); + } + fprintf(stderr, "This sleepTight() entry: "); + showFullTime(stderr, cur_entry); + fputc('\n', stderr); + fprintf(stderr, "Harvest children done: "); + showFullTime(stderr, cur); + fputc('\n', stderr); + fprintf(stderr, "Want sleepTight (%s) until: ", type == SLEEP_EVAL ? "eval" : "retry"); + showFullTime(stderr, sched); + fputc('\n', stderr); + fprintf(stderr, "This "); + dumpTask(t); + } + } + else { + unrealizenano(delay, &ts); + for (;;) { /* loop to catch early wakeup from nanosleep */ + if (ts.tv_sec < 0 || ts.tv_nsec > 999999999) { + fprintf(stderr, "sleepTight: invalid args: %ld %ld\n", + ts.tv_sec, ts.tv_nsec); + break; + } + sts = nanosleep(&ts, &tleft); + if (sts == 0 || (sts < 0 && errno != EINTR)) + break; + ts = tleft; } - sts = nanosleep(&ts, &tleft); - if (sts == 0 || (sts < 0 && errno != EINTR)) - break; - ts = tleft; } + last_t = t; + last_type = type; + last_sched = sched; } } @@ -1196,3 +1242,21 @@ dumpMetric(Metric *m) __dumpMetric(0, m); } +void +dumpTask(Task *t) +{ + int i; + fprintf(stderr, "Task dump @ " PRINTF_P_PFX "%p\n", t); + fprintf(stderr, " nth=%d delta=%.3f tick=%d next=" PRINTF_P_PFX "%p prev=" PRINTF_P_PFX "%p\n", t->nth, t->delta, t->tick, t->next, t->prev); + fprintf(stderr, " eval time: "); + showFullTime(stderr, t->eval); + fputc('\n', stderr); + fprintf(stderr, " retry time: "); + showFullTime(stderr, t->retry); + fputc('\n', stderr); + fprintf(stderr, " host=%s (%s)\n", symName(t->hosts->name), t->hosts->down ? "down" : "up"); + fprintf(stderr, " rules:\n"); + for (i = 0; i < t->nrules; i++) { + fprintf(stderr, " %s\n", symName(t->rules[i])); + } +} diff --git a/src/pmie/src/dstruct.h b/src/pmie/src/dstruct.h index 262a869..72d5f13 100644 --- a/src/pmie/src/dstruct.h +++ b/src/pmie/src/dstruct.h @@ -69,15 +69,6 @@ typedef double RealTime; /* wall clock time or interval */ #define DELTA_DFLT 10 /* default sample interval */ #define DELTA_MIN 0.1 /* minimum sample interval */ -/* convert timeval to RealTime */ -#define realize(t) (1.0e-6 * (RealTime)(t).tv_usec + (RealTime)(t).tv_sec) -/* convert RealTime to timeval */ -void unrealize(RealTime, struct timeval *); - -RealTime getReal(void); /* return current time */ -void reflectTime(RealTime); /* update time vars to reflect now */ -void sleepTight(RealTime); /* sleep until given RealTime */ - /*********************************************************************** * evaluator functions @@ -361,6 +352,20 @@ Expr *primary(Expr *, Expr *); void changeSmpls(Expr **, int); void instFetchExpr(Expr *); +/*********************************************************************** + * time methods + ***********************************************************************/ + +/* convert timeval to RealTime */ +#define realize(t) (1.0e-6 * (RealTime)(t).tv_usec + (RealTime)(t).tv_sec) +/* convert RealTime to timeval */ +void unrealize(RealTime, struct timeval *); +RealTime getReal(void); /* return current time */ +void reflectTime(RealTime); /* update time vars to reflect now */ +#define SLEEP_EVAL 0 +#define SLEEP_RETRY 1 +void sleepTight(Task *, int); /* sleep until retry or eval time */ + /* * diagnostic tracing */ @@ -368,6 +373,7 @@ void dumpRules(void); void dumpExpr(Expr *); void dumpTree(Expr *); void dumpMetric(Metric *); +void dumpTask(Task *); void __dumpExpr(int, Expr *); void __dumpTree(int, Expr *); void __dumpMetric(int, Metric *); diff --git a/src/pmie/src/eval.c b/src/pmie/src/eval.c index 7a0dbb8..330635a 100644 --- a/src/pmie/src/eval.c +++ b/src/pmie/src/eval.c @@ -751,7 +751,7 @@ run(void) now = t->retry; if (now > stop) break; - sleepTight(t->retry); + sleepTight(t, SLEEP_RETRY); enable(t); t->retry = waiting(t) ? now + RETRY : 0; } @@ -760,7 +760,7 @@ run(void) if (now > stop) break; reflectTime(t->delta); - sleepTight(t->eval); + sleepTight(t, SLEEP_EVAL); eval(t); t->tick++; t->eval = t->epoch + t->tick * t->delta; diff --git a/src/pmie/src/pragmatics.h b/src/pmie/src/pragmatics.h index a62834b..b5478e2 100644 --- a/src/pmie/src/pragmatics.h +++ b/src/pmie/src/pragmatics.h @@ -98,6 +98,9 @@ extern pmUnits countUnits; /* default context type */ extern int dfltConn; +/* flag processes spawned */ +extern int need_wait; + #endif /* PRAG_H */ diff --git a/src/pmie/src/show.c b/src/pmie/src/show.c index d573b18..1015b0a 100644 --- a/src/pmie/src/show.c +++ b/src/pmie/src/show.c @@ -705,6 +705,18 @@ showTime(FILE *f, RealTime rt) void +showFullTime(FILE *f, RealTime rt) +{ + time_t t = (time_t)rt; + char bfr[26]; + + pmCtime(&t, bfr); + bfr[24] = '\0'; + fprintf(f, "%s.%06d", bfr, (int)((rt-t)*1000000)); +} + + +void showSatisfyingValue(FILE *f, Expr *x) { char *string = NULL; diff --git a/src/pmie/src/show.h b/src/pmie/src/show.h index 0078414..a3d9908 100644 --- a/src/pmie/src/show.h +++ b/src/pmie/src/show.h @@ -28,4 +28,5 @@ void showValue(FILE *, Expr *); void showAnnotatedValue(FILE *, Expr *); void showSatisfyingValue(FILE *, Expr *); void showTime(FILE *, RealTime); +void showFullTime(FILE *, RealTime); size_t formatSatisfyingValue(char *, size_t, char **);