crond: simplify logging code

Slight change in behavior: now -l 5 will enable the same messages
formerly only enabled for -d 5. (Old behavior was non-sensical).

function                                             old     new   delta
reopen_logfile_to_stderr                               -      34     +34
log8                                                   -      26     +26
log7                                                   -      26     +26
log5                                                   -      26     +26
load_crontab                                         706     688     -18
rescan_crontab_dir                                   157     137     -20
crond_main                                          1486    1456     -30
fork_job                                             389     343     -46
crondlog                                             108      38     -70
------------------------------------------------------------------------------
(add/remove: 4/0 grow/shrink: 0/5 up/down: 112/-184)          Total: -72 bytes

Signed-off-by: Denys Vlasenko <vda.linux@googlemail.com>
This commit is contained in:
Denys Vlasenko 2014-04-30 14:49:52 +02:00
parent 3dfe0ae5a8
commit d5929d602e

View File

@ -125,12 +125,6 @@ enum {
OPT_c = (1 << 5), OPT_c = (1 << 5),
OPT_d = (1 << 6) * ENABLE_FEATURE_CROND_D, OPT_d = (1 << 6) * ENABLE_FEATURE_CROND_D,
}; };
#if ENABLE_FEATURE_CROND_D
# define DebugOpt (option_mask32 & OPT_d)
#else
# define DebugOpt 0
#endif
struct globals { struct globals {
unsigned log_level; /* = 8; */ unsigned log_level; /* = 8; */
@ -149,41 +143,50 @@ struct globals {
G.crontab_dir_name = CRONTABS; \ G.crontab_dir_name = CRONTABS; \
} while (0) } while (0)
/* Log levels:
* 0 is the most verbose, default 8.
* For some reason, in fact only 5, 7 and 8 are used.
*/
static void crondlog(unsigned level, const char *msg, va_list va)
{
if (level >= G.log_level) {
/*
* We are called only for info meesages.
* Warnings/errors use plain bb_[p]error_msg's, which
* need not touch syslog_level
* (they are ok with LOG_ERR default).
*/
syslog_level = LOG_INFO;
bb_verror_msg(msg, va, /* strerr: */ NULL);
syslog_level = LOG_ERR;
}
}
/* 0 is the most verbose, default 8 */ static void log5(const char *msg, ...)
#define LVL5 "\x05"
#define LVL7 "\x07"
#define LVL8 "\x08"
#define WARN9 "\x49"
#define DIE9 "\xc9"
/* level >= 20 is "error" */
#define ERR20 "\x14"
static void crondlog(const char *ctl, ...) __attribute__ ((format (printf, 1, 2)));
static void crondlog(const char *ctl, ...)
{ {
va_list va; va_list va;
unsigned level = (ctl[0] & 0x1f); va_start(va, msg);
crondlog(4, msg, va);
va_start(va, ctl);
if (level >= G.log_level) {
if (G.log_filename) {
/* If log to file, reopen log file at every write: */
int logfd = open_or_warn(G.log_filename, O_WRONLY | O_CREAT | O_APPEND);
if (logfd >= 0)
xmove_fd(logfd, STDERR_FILENO);
}
/* When we log to syslog, level > 8 is logged at LOG_ERR
* syslog level, level <= 8 is logged at LOG_INFO.
*/
syslog_level = (level > 8) ? LOG_ERR : LOG_INFO;
bb_verror_msg(ctl + 1, va, /* strerr: */ NULL);
}
va_end(va); va_end(va);
if (ctl[0] & 0x80)
exit(20);
} }
static void log7(const char *msg, ...)
{
va_list va;
va_start(va, msg);
crondlog(7, msg, va);
va_end(va);
}
static void log8(const char *msg, ...)
{
va_list va;
va_start(va, msg);
crondlog(8, msg, va);
va_end(va);
}
static const char DowAry[] ALIGN1 = static const char DowAry[] ALIGN1 =
"sun""mon""tue""wed""thu""fri""sat" "sun""mon""tue""wed""thu""fri""sat"
; ;
@ -293,12 +296,12 @@ static void ParseField(char *user, char *ary, int modvalue, int off,
if (*ptr) { if (*ptr) {
err: err:
crondlog(WARN9 "user %s: parse error at %s", user, base); bb_error_msg("user %s: parse error at %s", user, base);
return; return;
} }
if (DebugOpt && (G.log_level <= 5)) { /* like LVL5 */ /* can't use log5 (it inserts newlines), open-coding it */
/* can't use crondlog, it inserts '\n' */ if (G.log_level <= 5 && logmode != LOGMODE_SYSLOG) {
int i; int i;
for (i = 0; i < modvalue; ++i) for (i = 0; i < modvalue; ++i)
fprintf(stderr, "%d", (unsigned char)ary[i]); fprintf(stderr, "%d", (unsigned char)ary[i]);
@ -398,7 +401,7 @@ static void load_crontab(const char *fileName)
delete_cronfile(fileName); delete_cronfile(fileName);
if (!getpwnam(fileName)) { if (!getpwnam(fileName)) {
crondlog(LVL7 "ignoring file '%s' (no such user)", fileName); log7("ignoring file '%s' (no such user)", fileName);
return; return;
} }
@ -420,7 +423,7 @@ static void load_crontab(const char *fileName)
CronLine *line; CronLine *line;
if (!--maxLines) { if (!--maxLines) {
crondlog(WARN9 "user %s: too many lines", fileName); bb_error_msg("user %s: too many lines", fileName);
break; break;
} }
@ -428,8 +431,7 @@ static void load_crontab(const char *fileName)
if (!n) if (!n)
break; break;
if (DebugOpt) log5("user:%s entry:%s", fileName, parser->data);
crondlog(LVL5 "user:%s entry:%s", fileName, parser->data);
/* check if line is setting MAILTO= */ /* check if line is setting MAILTO= */
if (0 == strncmp(tokens[0], "MAILTO=", 7)) { if (0 == strncmp(tokens[0], "MAILTO=", 7)) {
@ -472,9 +474,7 @@ static void load_crontab(const char *fileName)
#endif #endif
/* copy command */ /* copy command */
line->cl_cmd = xstrdup(tokens[5]); line->cl_cmd = xstrdup(tokens[5]);
if (DebugOpt) { log5(" command:%s", tokens[5]);
crondlog(LVL5 " command:%s", tokens[5]);
}
pline = &line->cl_next; pline = &line->cl_next;
//bb_error_msg("M[%s]F[%s][%s][%s][%s][%s][%s]", mailTo, tokens[0], tokens[1], tokens[2], tokens[3], tokens[4], tokens[5]); //bb_error_msg("M[%s]F[%s][%s][%s][%s][%s][%s]", mailTo, tokens[0], tokens[1], tokens[2], tokens[3], tokens[4], tokens[5]);
} }
@ -519,17 +519,16 @@ static void rescan_crontab_dir(void)
/* Remove cron update file */ /* Remove cron update file */
unlink(CRONUPDATE); unlink(CRONUPDATE);
/* Re-chdir, in case directory was renamed & deleted */ /* Re-chdir, in case directory was renamed & deleted */
if (chdir(G.crontab_dir_name) < 0) { xchdir(G.crontab_dir_name);
crondlog(DIE9 "chdir(%s)", G.crontab_dir_name);
}
/* Scan directory and add associated users */ /* Scan directory and add associated users */
{ {
DIR *dir = opendir("."); DIR *dir = opendir(".");
struct dirent *den; struct dirent *den;
/* xopendir exists, but "can't open '.'" is not informative */
if (!dir) if (!dir)
crondlog(DIE9 "chdir(%s)", "."); /* exits */ bb_error_msg_and_die("can't open '%s'", G.crontab_dir_name);
while ((den = readdir(dir)) != NULL) { while ((den = readdir(dir)) != NULL) {
if (strchr(den->d_name, '.') != NULL) { if (strchr(den->d_name, '.') != NULL) {
continue; continue;
@ -576,10 +575,8 @@ static void change_user(struct passwd *pas)
/* careful: we're after vfork! */ /* careful: we're after vfork! */
change_identity(pas); /* - initgroups, setgid, setuid */ change_identity(pas); /* - initgroups, setgid, setuid */
if (chdir(pas->pw_dir) < 0) { if (chdir(pas->pw_dir) < 0) {
crondlog(WARN9 "chdir(%s)", pas->pw_dir); bb_error_msg("can't change directory to '%s'", pas->pw_dir);
if (chdir(CRON_DIR) < 0) { xchdir(CRON_DIR);
crondlog(DIE9 "chdir(%s)", CRON_DIR); /* exits */
}
} }
} }
@ -591,25 +588,25 @@ fork_job(const char *user, int mailFd,
const char *prog, const char *prog,
const char *shell_cmd /* if NULL, we run sendmail */ const char *shell_cmd /* if NULL, we run sendmail */
) { ) {
smallint sv_logmode;
struct passwd *pas; struct passwd *pas;
pid_t pid; pid_t pid;
/* prepare things before vfork */ /* prepare things before vfork */
pas = getpwnam(user); pas = getpwnam(user);
if (!pas) { if (!pas) {
crondlog(WARN9 "can't get uid for %s", user); bb_error_msg("can't get uid for %s", user);
goto err; goto err;
} }
set_env_vars(pas); set_env_vars(pas);
sv_logmode = logmode;
pid = vfork(); pid = vfork();
if (pid == 0) { if (pid == 0) {
/* CHILD */ /* CHILD */
/* initgroups, setgid, setuid, and chdir to home or CRON_DIR */ /* initgroups, setgid, setuid, and chdir to home or CRON_DIR */
change_user(pas); change_user(pas);
if (DebugOpt) { log5("child running %s", prog);
crondlog(LVL5 "child running %s", prog);
}
if (mailFd >= 0) { if (mailFd >= 0) {
xmove_fd(mailFd, shell_cmd ? 1 : 0); xmove_fd(mailFd, shell_cmd ? 1 : 0);
dup2(1, 2); dup2(1, 2);
@ -617,15 +614,17 @@ fork_job(const char *user, int mailFd,
/* crond 3.0pl1-100 puts tasks in separate process groups */ /* crond 3.0pl1-100 puts tasks in separate process groups */
bb_setpgrp(); bb_setpgrp();
execlp(prog, prog, (shell_cmd ? "-c" : SENDMAIL_ARGS), shell_cmd, (char *) NULL); execlp(prog, prog, (shell_cmd ? "-c" : SENDMAIL_ARGS), shell_cmd, (char *) NULL);
crondlog(ERR20 "can't execute '%s' for user %s", prog, user); /*
if (shell_cmd) { * I want this error message on stderr too,
fdprintf(1, "Exec failed: %s -c %s\n", prog, shell_cmd); * even if other messages go only to syslog:
} */
_exit(EXIT_SUCCESS); logmode |= LOGMODE_STDIO;
bb_error_msg_and_die("can't execute '%s' for user %s", prog, user);
} }
logmode = sv_logmode;
if (pid < 0) { if (pid < 0) {
crondlog(ERR20 "can't vfork"); bb_perror_msg("vfork");
err: err:
pid = 0; pid = 0;
} /* else: PARENT, FORK SUCCESS */ } /* else: PARENT, FORK SUCCESS */
@ -658,7 +657,7 @@ static void start_one_job(const char *user, CronLine *line)
line->cl_cmd); line->cl_cmd);
line->cl_empty_mail_size = lseek(mailFd, 0, SEEK_CUR); line->cl_empty_mail_size = lseek(mailFd, 0, SEEK_CUR);
} else { } else {
crondlog(ERR20 "can't create mail file %s for user %s, " bb_error_msg("can't create mail file %s for user %s, "
"discarding output", mailFile, user); "discarding output", mailFile, user);
} }
} }
@ -731,7 +730,7 @@ static void start_one_job(const char *user, CronLine *line)
pas = getpwnam(user); pas = getpwnam(user);
if (!pas) { if (!pas) {
crondlog(WARN9 "can't get uid for %s", user); bb_error_msg("can't get uid for %s", user);
goto err; goto err;
} }
@ -744,18 +743,14 @@ static void start_one_job(const char *user, CronLine *line)
/* CHILD */ /* CHILD */
/* initgroups, setgid, setuid, and chdir to home or CRON_DIR */ /* initgroups, setgid, setuid, and chdir to home or CRON_DIR */
change_user(pas); change_user(pas);
if (DebugOpt) { log5("child running %s", DEFAULT_SHELL);
crondlog(LVL5 "child running %s", DEFAULT_SHELL);
}
/* crond 3.0pl1-100 puts tasks in separate process groups */ /* crond 3.0pl1-100 puts tasks in separate process groups */
bb_setpgrp(); bb_setpgrp();
execl(DEFAULT_SHELL, DEFAULT_SHELL, "-c", line->cl_cmd, (char *) NULL); execl(DEFAULT_SHELL, DEFAULT_SHELL, "-c", line->cl_cmd, (char *) NULL);
crondlog(ERR20 "can't execute '%s' for user %s", DEFAULT_SHELL, user); bb_error_msg_and_die("can't execute '%s' for user %s", DEFAULT_SHELL, user);
_exit(EXIT_SUCCESS);
} }
if (pid < 0) { if (pid < 0) {
/* FORK FAILED */ bb_perror_msg("vfork");
crondlog(ERR20 "can't vfork");
err: err:
pid = 0; pid = 0;
} }
@ -787,24 +782,20 @@ static void flag_starting_jobs(time_t t1, time_t t2)
ptm = localtime(&t); ptm = localtime(&t);
for (file = G.cron_files; file; file = file->cf_next) { for (file = G.cron_files; file; file = file->cf_next) {
if (DebugOpt) log5("file %s:", file->cf_username);
crondlog(LVL5 "file %s:", file->cf_username);
if (file->cf_deleted) if (file->cf_deleted)
continue; continue;
for (line = file->cf_lines; line; line = line->cl_next) { for (line = file->cf_lines; line; line = line->cl_next) {
if (DebugOpt) log5(" line %s", line->cl_cmd);
crondlog(LVL5 " line %s", line->cl_cmd);
if (line->cl_Mins[ptm->tm_min] if (line->cl_Mins[ptm->tm_min]
&& line->cl_Hrs[ptm->tm_hour] && line->cl_Hrs[ptm->tm_hour]
&& (line->cl_Days[ptm->tm_mday] || line->cl_Dow[ptm->tm_wday]) && (line->cl_Days[ptm->tm_mday] || line->cl_Dow[ptm->tm_wday])
&& line->cl_Mons[ptm->tm_mon] && line->cl_Mons[ptm->tm_mon]
) { ) {
if (DebugOpt) { log5(" job: %d %s",
crondlog(LVL5 " job: %d %s",
(int)line->cl_pid, line->cl_cmd); (int)line->cl_pid, line->cl_cmd);
}
if (line->cl_pid > 0) { if (line->cl_pid > 0) {
crondlog(LVL8 "user %s: process already running: %s", log8("user %s: process already running: %s",
file->cf_username, line->cl_cmd); file->cf_username, line->cl_cmd);
} else if (line->cl_pid == 0) { } else if (line->cl_pid == 0) {
line->cl_pid = -1; line->cl_pid = -1;
@ -833,7 +824,7 @@ static void start_jobs(void)
start_one_job(file->cf_username, line); start_one_job(file->cf_username, line);
pid = line->cl_pid; pid = line->cl_pid;
crondlog(LVL8 "USER %s pid %3d cmd %s", log8("USER %s pid %3d cmd %s",
file->cf_username, (int)pid, line->cl_cmd); file->cf_username, (int)pid, line->cl_cmd);
if (pid < 0) { if (pid < 0) {
file->cf_wants_starting = 1; file->cf_wants_starting = 1;
@ -885,6 +876,15 @@ static int check_completions(void)
return num_still_running; return num_still_running;
} }
static void reopen_logfile_to_stderr(void)
{
if (G.log_filename) {
int logfd = open_or_warn(G.log_filename, O_WRONLY | O_CREAT | O_APPEND);
if (logfd >= 0)
xmove_fd(logfd, STDERR_FILENO);
}
}
int crond_main(int argc, char **argv) MAIN_EXTERNALLY_VISIBLE; int crond_main(int argc, char **argv) MAIN_EXTERNALLY_VISIBLE;
int crond_main(int argc UNUSED_PARAM, char **argv) int crond_main(int argc UNUSED_PARAM, char **argv)
{ {
@ -916,10 +916,12 @@ int crond_main(int argc UNUSED_PARAM, char **argv)
logmode = LOGMODE_SYSLOG; logmode = LOGMODE_SYSLOG;
} }
reopen_logfile_to_stderr();
xchdir(G.crontab_dir_name); xchdir(G.crontab_dir_name);
//signal(SIGHUP, SIG_IGN); /* ? original crond dies on HUP... */ //signal(SIGHUP, SIG_IGN); /* ? original crond dies on HUP... */
xsetenv("SHELL", DEFAULT_SHELL); /* once, for all future children */ xsetenv("SHELL", DEFAULT_SHELL); /* once, for all future children */
crondlog(LVL8 "crond (busybox "BB_VER") started, log level %d", G.log_level); log8("crond (busybox "BB_VER") started, log level %d", G.log_level);
rescan_crontab_dir(); rescan_crontab_dir();
write_pidfile(CONFIG_PID_FILE_PATH "/crond.pid"); write_pidfile(CONFIG_PID_FILE_PATH "/crond.pid");
@ -932,14 +934,14 @@ int crond_main(int argc UNUSED_PARAM, char **argv)
time_t t1; time_t t1;
long dt; long dt;
t1 = t2;
/* Synchronize to 1 minute, minimum 1 second */ /* Synchronize to 1 minute, minimum 1 second */
sleep(sleep_time - (time(NULL) % sleep_time) + 1); t1 = t2;
sleep(sleep_time - (time(NULL) % sleep_time));
t2 = time(NULL); t2 = time(NULL);
dt = (long)t2 - (long)t1; dt = (long)t2 - (long)t1;
reopen_logfile_to_stderr();
/* /*
* The file 'cron.update' is checked to determine new cron * The file 'cron.update' is checked to determine new cron
* jobs. The directory is rescanned once an hour to deal * jobs. The directory is rescanned once an hour to deal
@ -967,10 +969,9 @@ int crond_main(int argc UNUSED_PARAM, char **argv)
rescan_crontab_dir(); rescan_crontab_dir();
} }
process_cron_update_file(); process_cron_update_file();
if (DebugOpt) log5("wakeup dt=%ld", dt);
crondlog(LVL5 "wakeup dt=%ld", dt);
if (dt < -60 * 60 || dt > 60 * 60) { if (dt < -60 * 60 || dt > 60 * 60) {
crondlog(WARN9 "time disparity of %ld minutes detected", dt / 60); bb_error_msg("time disparity of %ld minutes detected", dt / 60);
/* and we do not run any jobs in this case */ /* and we do not run any jobs in this case */
} else if (dt > 0) { } else if (dt > 0) {
/* Usual case: time advances forward, as expected */ /* Usual case: time advances forward, as expected */