From: Thibault Godouet Date: Thu, 12 Jun 2014 13:10:24 +0000 (+0100) Subject: quote job shell commands in logs to make the messages clearer X-Git-Tag: ver3_2_0~2 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=014b12ca4358392772015cfdadcc1782d36dd402;p=thirdparty%2Ffcron.git quote job shell commands in logs to make the messages clearer --- diff --git a/conf.c b/conf.c index 42eff29..5f808d1 100644 --- a/conf.c +++ b/conf.c @@ -309,7 +309,7 @@ synchronize_file(char *file_name, int is_system_startup) struct tm *ftime; ftime = localtime(&new_l->cl_nextexe); debug - (" from last conf: %s next exec %04d-%02d-%02d" + (" from last conf: '%s' next exec %04d-%02d-%02d" " wday:%d %02d:%02d:%02d (system time)", new_l->cl_shell, (ftime->tm_year + 1900), (ftime->tm_mon + 1), ftime->tm_mday, @@ -857,7 +857,7 @@ add_line_to_file(cl_t * cl, cf_t * cf, uid_t runas, char *runas_str, else { /* job has been stopped during execution : * launch it again */ - warn("job %s did not finish : running it again.", cl->cl_shell); + warn("job '%s' did not finish : running it again.", cl->cl_shell); set_serial_once(cl->cl_option); add_serial_job(cl, -1); } @@ -914,7 +914,7 @@ add_line_to_file(cl_t * cl, cf_t * cf, uid_t runas, char *runas_str, else { /* run bootrun jobs */ cl->cl_remain = cl->cl_runfreq; - debug(" boot-run %s", cl->cl_shell); + debug(" boot-run '%s'", cl->cl_shell); if (!is_lavg(cl->cl_option)) { set_serial_once(cl->cl_option); add_serial_job(cl, -1); @@ -966,7 +966,7 @@ add_line_to_file(cl_t * cl, cf_t * cf, uid_t runas, char *runas_str, if (cl->cl_nextexe < now || cl->cl_nextexe > TIME_T_MAX) { /* there was an integer overflow! */ error - ("Error while setting next exe time for job %s: cl_nextexe" + ("Error while setting next exe time for job '%s': cl_nextexe" " overflowed (case1). now=%lu, cl_timefreq=%lu, cl_nextexe=%lu.", cl->cl_shell, now, cl->cl_timefreq, cl->cl_nextexe); error @@ -982,7 +982,7 @@ add_line_to_file(cl_t * cl, cf_t * cf, uid_t runas, char *runas_str, /* either there was an integer overflow, or the slept time is incorrect * (e.g. fcron didn't shut down cleanly and the fcrontab wasn't saved correctly) */ error - ("Error while setting next exe time for job %s: cl_nextexe" + ("Error while setting next exe time for job '%s': cl_nextexe" " overflowed (case2). now=%lu, cl_timefreq=%lu, cl_nextexe=%lu. " "Did fcron shut down cleanly?", cl->cl_shell, now, cl->cl_timefreq, cl->cl_nextexe); @@ -1000,7 +1000,7 @@ add_line_to_file(cl_t * cl, cf_t * cf, uid_t runas, char *runas_str, if (debug_opt && !(is_runonce(cl->cl_option) && is_hasrun(cl->cl_option))) { struct tm *ftime; ftime = localtime(&(cl->cl_nextexe)); - debug(" cmd %s next exec %04d-%02d-%02d wday:%d %02d:%02d:%02d" + debug(" cmd '%s' next exec %04d-%02d-%02d wday:%d %02d:%02d:%02d" " (system time)", cl->cl_shell, (ftime->tm_year + 1900), (ftime->tm_mon + 1), ftime->tm_mday, ftime->tm_wday, ftime->tm_hour, ftime->tm_min, @@ -1062,7 +1062,7 @@ delete_file(const char *user_name) for (l = lavg_list_first(lavg_list); l != NULL; l = lavg_list_next(lavg_list)) if (l->l_line->cl_file == file) { - debug("removing %s from lavg queue", l->l_line->cl_shell); + debug("removing '%s' from lavg queue", l->l_line->cl_shell); lavg_list_remove_cur(lavg_list); } @@ -1074,7 +1074,7 @@ delete_file(const char *user_name) alloc_safe(serial_array_size * sizeof(cl_t *), "serial queue"); } - debug("removing %s from serial queue", + debug("removing '%s' from serial queue", serial_array[i]->cl_shell); serial_num--; serial_array[i]->cl_numexe--; diff --git a/database.c b/database.c index 51278ab..c76e629 100644 --- a/database.c +++ b/database.c @@ -70,7 +70,7 @@ test_jobs(void) } if (is_runonce(j->j_line->cl_option) && is_hasrun(j->j_line->cl_option)) { - explain("Line %s has runonce set: not re-scheduling it.", + explain("Line '%s' has runonce set: not re-scheduling it.", j->j_line->cl_shell); job_queue_remove(j->j_line); } @@ -180,10 +180,10 @@ run_normal_job(cl_t * line, int info_fd) (is_exe_sev(line->cl_option) && line->cl_numexe < UCHAR_MAX)) { line->cl_numexe += 1; run_queue_job(line); - send_msg_fd(info_fd, "Job %s started.", line->cl_shell); + send_msg_fd(info_fd, "Job '%s' started.", line->cl_shell); } else { - warn_fd(info_fd, " process already running: %s's %s", + warn_fd(info_fd, " process already running: %s's '%s'", line->cl_file->cf_user, line->cl_shell); } @@ -332,18 +332,19 @@ add_serial_job(cl_t * line, int info_fd) * (we consider serial jobs currently running as in the queue) */ if ((is_serial_sev(line->cl_option) && line->cl_numexe >= UCHAR_MAX) || (!is_serial_sev(line->cl_option) && line->cl_numexe > 0)) { - send_msg_fd_debug(info_fd, "already in serial queue %s", + send_msg_fd_debug(info_fd, "already in serial queue '%s'", line->cl_shell); return; } - send_msg_fd_debug(info_fd, "inserting in serial queue %s", line->cl_shell); + send_msg_fd_debug(info_fd, "inserting in serial queue '%s'", + line->cl_shell); if (serial_num >= serial_array_size) { if (serial_num >= serial_queue_max) { error_fd(info_fd, "Could not add job : serial queue is full " "(%d jobs). Consider using option serialonce, fcron's " - "option -m and/or -q : %s", serial_queue_max, + "option -m and/or -q : '%s'", serial_queue_max, line->cl_shell); if (is_notice_notrun(line->cl_option)) mail_notrun(line, QUEUE_FULL, NULL); @@ -398,19 +399,21 @@ add_lavg_job(cl_t * line, int info_fd) * (we consider serial jobs currently running as in the queue) */ if ((is_lavg_sev(line->cl_option) && line->cl_numexe >= UCHAR_MAX) || (!is_lavg_sev(line->cl_option) && line->cl_numexe > 0)) { - send_msg_fd_debug(info_fd, "already in lavg queue %s", line->cl_shell); + send_msg_fd_debug(info_fd, "already in lavg queue '%s'", + line->cl_shell); return; } /* // */ - send_msg_fd_debug(info_fd, "inserting in lavg queue %s", line->cl_shell); + send_msg_fd_debug(info_fd, "inserting in lavg queue '%s'", line->cl_shell); /* // */ /* append job to the list of lavg job */ lavg_entry = lavg_list_add_line(lavg_list, line); if (lavg_entry == NULL) { - error_fd(info_fd, "Could not add job : lavg queue is full (%d jobs)." + error_fd(info_fd, + "Could not add job '%s' : lavg queue is full (%d jobs)." " Consider using options lavgonce, until, strict and/or " - "fcron's option -q.", lavg_list->max_entries, line->cl_shell); + "fcron's option -q.", line->cl_shell, lavg_list->max_entries); if (is_notice_notrun(line->cl_option)) mail_notrun(line, QUEUE_FULL, NULL); return; @@ -537,7 +540,7 @@ wait_all(int *counter) } else { - debug("job finished: %s", e->e_line->cl_shell); + debug("job finished: '%s'", e->e_line->cl_shell); e->e_line->cl_numexe -= 1; e->e_line->cl_file->cf_running -= 1; @@ -761,7 +764,7 @@ goto_beginning_next_period_periodical(cl_t * line, struct tm *ftime) if (debug_opt) set_wday(ftime); - debug(" %s beginning of next period %04d-%02d-%02d wday:%d %02d:%02d " + debug(" '%s' beginning of next period %04d-%02d-%02d wday:%d %02d:%02d " "(tzdiff=%d, timezone=%s)", line->cl_shell, (ftime->tm_year + 1900), (ftime->tm_mon + 1), ftime->tm_mday, ftime->tm_wday, ftime->tm_hour, ftime->tm_min, line->cl_file->cf_tzdiff, @@ -890,7 +893,7 @@ move_time_to(int where, cl_t * line, struct tm *ftime) ftime->tm_mon = 0; ftime->tm_year++; if (--year_limit <= 0) { - error("Can't found a non matching date for %s " + error("Can't found a non matching date for '%s' " "in the next %d years. Maybe this line " "is corrupted : consider reinstalling " "the fcrontab", line->cl_shell, @@ -944,14 +947,15 @@ move_time_to(int where, cl_t * line, struct tm *ftime) } } - debug(" %s %s %04d-%02d-%02d wday:%d %02d:%02d (tzdiff=%d, timezone=%s)", - line->cl_shell, - (where == - END_OF_INTERVAL) ? "end of interval" : "begin of next period", - (ftime->tm_year + 1900), (ftime->tm_mon + 1), ftime->tm_mday, - ftime->tm_wday, ftime->tm_hour, ftime->tm_min, - line->cl_file->cf_tzdiff, - (line->cl_tz != NULL) ? line->cl_tz : "localtime"); + debug + (" '%s' %s %04d-%02d-%02d wday:%d %02d:%02d (tzdiff=%d, timezone=%s)", + line->cl_shell, + (where == + END_OF_INTERVAL) ? "end of interval" : "begin of next period", + (ftime->tm_year + 1900), (ftime->tm_mon + 1), ftime->tm_mday, + ftime->tm_wday, ftime->tm_hour, ftime->tm_min, + line->cl_file->cf_tzdiff, + (line->cl_tz != NULL) ? line->cl_tz : "localtime"); } @@ -1013,7 +1017,7 @@ set_next_exe(cl_t * line, char option, int info_fd) if (i >= 12) { ftime.tm_year++; if (--year_limit <= 0) { - error("Can't found a matching date for %s in the next %d" + error("Can't found a matching date for '%s' in the next %d" " years. Maybe this line is corrupted : consider" " reinstalling the fcrontab.", line->cl_shell, MAXYEAR_SCHEDULE_TIME); @@ -1155,12 +1159,13 @@ set_next_exe(cl_t * line, char option, int info_fd) struct tm int_end; time_t int_end_timet; - debug(" cmd: %s begin int exec %04d-%02d-%02d wday:%d %02d:%02d " - "(tzdiff=%d, timezone=%s)", line->cl_shell, - (ftime.tm_year + 1900), (ftime.tm_mon + 1), ftime.tm_mday, - ftime.tm_wday, ftime.tm_hour, ftime.tm_min, - line->cl_file->cf_tzdiff, - (line->cl_tz != NULL) ? line->cl_tz : "localtime"); + debug + (" cmd: '%s' begin int exec %04d-%02d-%02d wday:%d %02d:%02d " + "(tzdiff=%d, timezone=%s)", line->cl_shell, + (ftime.tm_year + 1900), (ftime.tm_mon + 1), ftime.tm_mday, + ftime.tm_wday, ftime.tm_hour, ftime.tm_min, + line->cl_file->cf_tzdiff, + (line->cl_tz != NULL) ? line->cl_tz : "localtime"); memcpy(&int_end, &ftime, sizeof(int_end)); move_time_to(END_OF_INTERVAL, line, &int_end); @@ -1189,7 +1194,7 @@ set_next_exe(cl_t * line, char option, int info_fd) memcpy(&ftime, ft, sizeof(ftime)); } send_msg_fd_debug(info_fd, - " cmd: %s next exec %04d-%02d-%02d wday:%d " + " cmd: '%s' next exec %04d-%02d-%02d wday:%d " "%02d:%02d:%02d (tzdiff=%d, timezone=%s)", line->cl_shell, (ftime.tm_year + 1900), (ftime.tm_mon + 1), ftime.tm_mday, ftime.tm_wday, @@ -1209,7 +1214,7 @@ set_next_exe(cl_t * line, char option, int info_fd) * an unknown bug in this function. */ if (line->cl_nextexe <= now) { - error("BUG ??? Fcron thinks the next exe time of %s is %ld, " + error("BUG ??? Fcron thinks the next exe time of '%s' is %ld, " "hence before now (%ld). To avoid infinite loop, nextexe" " will be set at now+5s.", line->cl_shell, line->cl_nextexe); line->cl_nextexe = now + 5; @@ -1235,11 +1240,11 @@ set_next_exe(cl_t * line, char option, int info_fd) if (line->cl_nextexe <= basetime) { /* either there was an integer overflow, or the slept time is incorrect * (e.g. fcron didn't shut down cleanly and the fcrontab wasn't saved correctly) */ - error("Error while setting next exe time for job %s: cl_nextexe" - " overflowed (case3). basetime=%lu, cl_timefreq=%lu, cl_nextexe=%lu. " - "Did fcron shut down cleanly?", - line->cl_shell, basetime, line->cl_timefreq, - line->cl_nextexe); + error + ("Error while setting next exe time for job '%s': cl_nextexe" + " overflowed (case3). basetime=%lu, cl_timefreq=%lu, cl_nextexe=%lu. " + "Did fcron shut down cleanly?", line->cl_shell, basetime, + line->cl_timefreq, line->cl_nextexe); error ("Setting cl_nextexe to now+cl_timefreq to prevent an infinite loop."); line->cl_nextexe = now + line->cl_timefreq; @@ -1255,7 +1260,7 @@ set_next_exe(cl_t * line, char option, int info_fd) memcpy(&ftime, ft, sizeof(struct tm)); send_msg_fd_debug(info_fd, - " cmd: %s next exec %04d-%02d-%02d wday:%d " + " cmd: '%s' next exec %04d-%02d-%02d wday:%d " "%02d:%02d:%02d (system time)", line->cl_shell, (ftime.tm_year + 1900), (ftime.tm_mon + 1), ftime.tm_mday, ftime.tm_wday, ftime.tm_hour, @@ -1282,7 +1287,7 @@ set_next_exe_notrun(cl_t * line, char context) int tz_changed = 0; /* // */ - debug(" set_next_exe_notrun : %s %d", line->cl_shell, context); + debug(" set_next_exe_notrun : '%s' %d", line->cl_shell, context); /* // */ @@ -1362,7 +1367,7 @@ mail_notrun(cl_t * line, char context, struct tm *since) switch (pid = fork()) { case -1: - error_e("Fork error : could not mail for not run %s", line->cl_shell); + error_e("Fork error : could not mail for not run '%s'", line->cl_shell); return; case 0: /* child */ @@ -1371,7 +1376,7 @@ mail_notrun(cl_t * line, char context, struct tm *since) /* parent */ /* // */ - debug("Reporting by mail non execution of %s (pid %d)", + debug("Reporting by mail non execution of '%s' (pid %d)", line->cl_shell, pid); /* // */ @@ -1398,7 +1403,7 @@ mail_notrun(cl_t * line, char context, struct tm *since) switch (context) { case SYSDOWN: - fprintf(mailf, "Line %s has not run since and including " + fprintf(mailf, "Line '%s' has not run since and including " "%04d-%02d-%02d wday:%d %02d:%02d (timezone=%s)\n" "due to system's down state.\n", line->cl_shell, (since->tm_year + 1900), (since->tm_mon + 1), @@ -1410,7 +1415,7 @@ mail_notrun(cl_t * line, char context, struct tm *since) time.tm_mday, time.tm_wday, time.tm_hour, time.tm_min); break; case LAVG: - fprintf(mailf, "Line %s has not run since and including " + fprintf(mailf, "Line '%s' has not run since and including " "%04d-%02d-%02d wday:%d %02d:%02d (timezone=%s)\n", line->cl_shell, (since->tm_year + 1900), (since->tm_mon + 1), since->tm_mday, since->tm_wday, since->tm_hour, since->tm_min, @@ -1425,7 +1430,8 @@ mail_notrun(cl_t * line, char context, struct tm *since) time.tm_min, (line->cl_tz) ? line->cl_tz : "system's"); break; case QUEUE_FULL: - fprintf(mailf, "Line %s couldn't be added to lavg or serial queue which" + fprintf(mailf, + "Line '%s' couldn't be added to lavg or serial queue which" " is full ( %04d-%02d-%02d wday:%d %02d:%02d (timezone=%s)).\n", line->cl_shell, (time.tm_year + 1900), (time.tm_mon + 1), time.tm_mday, time.tm_wday, time.tm_hour, time.tm_min, @@ -1433,7 +1439,7 @@ mail_notrun(cl_t * line, char context, struct tm *since) fprintf(mailf, "Consider using options lavgonce, until, strict, " "serialonce and/or fcron's option -m.\n"); - fprintf(mailf, "Note that job %s has not run.\n", line->cl_shell); + fprintf(mailf, "Note that job '%s' has not run.\n", line->cl_shell); break; } @@ -1478,7 +1484,7 @@ check_lavg(time_t lim) && l->l_until < now) { if (!is_run_if_late(l->l_line->cl_option)) { if (!is_nolog(l->l_line->cl_option)) - explain("Interval of execution exceeded : %s (not run)", + explain("Interval of execution exceeded : '%s' (not run)", l->l_line->cl_shell); /* set time of the next execution and send a mail if needed */ @@ -1493,7 +1499,7 @@ check_lavg(time_t lim) lavg_list_remove_cur(lavg_list); } else { - debug("until %s %d", l->l_line->cl_shell, l->l_until); + debug("until '%s' %d", l->l_line->cl_shell, l->l_until); run_lavg_job(l); lavg_list_remove_cur(lavg_list); } @@ -1530,7 +1536,7 @@ check_lavg(time_t lim) || l_avg[2] < l->l_line->cl_lavg[2]) ) ) { - debug("lavg %s %s %.0f:%d %.0f:%d %.0f:%d", + debug("lavg '%s' %s %.0f:%d %.0f:%d %.0f:%d", l->l_line->cl_shell, (is_lor(l->l_line->cl_option)) ? "or" : "and", l_avg[0], l->l_line->cl_lavg[0], diff --git a/fcron.c b/fcron.c index 8155ee6..fb425ed 100644 --- a/fcron.c +++ b/fcron.c @@ -173,7 +173,7 @@ print_schedule(void) explain(" File %s", cf->cf_user); for (cl = cf->cf_line_base; cl; cl = cl->cl_next) { ftime = localtime(&(cl->cl_nextexe)); - explain(" cmd %s next exec %04d-%02d-%02d wday:%d %02d:%02d" + explain(" cmd '%s' next exec %04d-%02d-%02d wday:%d %02d:%02d" " (system time)", cl->cl_shell, (ftime->tm_year + 1900), (ftime->tm_mon + 1), ftime->tm_mday, ftime->tm_wday, ftime->tm_hour, @@ -832,6 +832,7 @@ main_loop() check_signal(); debug("\n"); + test_jobs(); while (serial_num > 0 && serial_running < serial_max_running) diff --git a/job.c b/job.c index ac21979..24b1f82 100644 --- a/job.c +++ b/job.c @@ -157,7 +157,7 @@ setup_user_and_env(struct cl_t *cl, struct passwd *pas, retcode = pam_start("fcron", pas->pw_name, &apamconv, &pamh); if (retcode != PAM_SUCCESS) - die_pame(pamh, retcode, "Could not start PAM for %s", cl->cl_shell); + die_pame(pamh, retcode, "Could not start PAM for '%s'", cl->cl_shell); /* Some system seem to need that pam_authenticate() call. * Anyway, we have no way to authentificate the user : * we must set auth to pam_permit. */ @@ -522,7 +522,7 @@ run_job(struct exe_t *exeent) switch (pid = fork()) { case -1: - error_e("Fork error : could not exec \"%s\"", line->cl_shell); + error_e("Fork error : could not exec '%s'", line->cl_shell); return ERR; break; @@ -594,7 +594,7 @@ run_job(struct exe_t *exeent) /* now, run the job */ switch (pid = fork()) { case -1: - error_e("Fork error : could not exec \"%s\"", line->cl_shell); + error_e("Fork error : could not exec '%s'", line->cl_shell); if (write(pipe_pid_fd[1], &pid, sizeof(pid)) < 0) error_e("could not write child pid to pipe_pid_fd[1]"); xclose_check(&(pipe_fd[0]), "child's pipe_fd[0]"); @@ -672,7 +672,7 @@ run_job(struct exe_t *exeent) #endif /* CHECKRUNJOB */ if (!is_nolog(line->cl_option)) - explain("Job %s started for user %s (pid %d)", + explain("Job '%s' started for user %s (pid %d)", line->cl_shell, line->cl_file->cf_user, pid); if (!to_stdout && is_mail(line->cl_option)) { @@ -686,7 +686,7 @@ run_job(struct exe_t *exeent) mailbuf[sizeof(mailbuf) - 1] = '\0'; while (fgets(mailbuf, sizeof(mailbuf), pipef) != NULL) if (fputs(mailbuf, mailf) < 0) - warn("fputs() failed to write to mail file for job %s (pid %d)", line->cl_shell, pid); + warn("fputs() failed to write to mail file for job '%s' (pid %d)", line->cl_shell, pid); /* (closes also pipe_fd[0]): */ xfclose_check(&pipef, "child's pipef"); } @@ -796,28 +796,28 @@ end_job(cl_t * line, int status, FILE * mailf, short mailpos, m = (mail_output == 1) ? " (mailing output)" : ""; if (WIFEXITED(status) && WEXITSTATUS(status) == 0) { if (!is_nolog(line->cl_option)) - explain("Job %s completed%s", line->cl_shell, m); + explain("Job '%s' completed%s", line->cl_shell, m); } else if (WIFEXITED(status)) { - warn("Job %s terminated (exit status: %d)%s", + warn("Job '%s' terminated (exit status: %d)%s", line->cl_shell, WEXITSTATUS(status), m); /* there was an error : in order to inform the user by mail, we need * to add some data to mailf */ if (mailf != NULL) - fprintf(mailf, "Job %s terminated (exit status: %d)%s", + fprintf(mailf, "Job '%s' terminated (exit status: %d)%s", line->cl_shell, WEXITSTATUS(status), m); } else if (WIFSIGNALED(status)) { - error("Job %s terminated due to signal %d%s", + error("Job '%s' terminated due to signal %d%s", line->cl_shell, WTERMSIG(status), m); if (mailf != NULL) - fprintf(mailf, "Job %s terminated due to signal %d%s", + fprintf(mailf, "Job '%s' terminated due to signal %d%s", line->cl_shell, WTERMSIG(status), m); } else { /* is this possible? */ - error("Job %s terminated abnormally %s", line->cl_shell, m); + error("Job '%s' terminated abnormally %s", line->cl_shell, m); if (mailf != NULL) - fprintf(mailf, "Job %s terminated abnormally %s", line->cl_shell, + fprintf(mailf, "Job '%s' terminated abnormally %s", line->cl_shell, m); }