From e28a56e219102af9e866e811de5b0efd6bd8155c Mon Sep 17 00:00:00 2001 From: Michiel Broek Date: Sun, 29 Jan 2006 16:47:32 +0000 Subject: [PATCH] Made logging multithread aware --- ChangeLog | 1 + mbtask/mbtask.c | 93 ++++++++++++++++++++++++++++++++--------------- mbtask/taskibc.c | 29 +++++++++++---- mbtask/taskutil.c | 90 +++++++++++++++++---------------------------- mbtask/taskutil.h | 1 - 5 files changed, 120 insertions(+), 94 deletions(-) diff --git a/ChangeLog b/ChangeLog index 9796ad65..facc82bf 100644 --- a/ChangeLog +++ b/ChangeLog @@ -5,6 +5,7 @@ v0.83.11 28-Jan-2006 mbtask: Added logging for possible detection of dialup IBC neighbour address change. + Made logging multithread aware. v0.83.10 25-Jan-2006 - 28-Jan-2006 diff --git a/mbtask/mbtask.c b/mbtask/mbtask.c index 0bbe8f69..776ca4e8 100644 --- a/mbtask/mbtask.c +++ b/mbtask/mbtask.c @@ -465,11 +465,6 @@ pid_t launch(char *cmd, char *opts, char *name, int tasktype) return 0; } - if (lock_ibc((char *)"launch")) { - return 0; - } - Syslog('r', "launch() mutex locked"); - pid = fork(); switch (pid) { case -1: @@ -520,9 +515,6 @@ pid_t launch(char *cmd, char *opts, char *name, int tasktype) } } - unlock_ibc((char *)"launch"); - Syslog('r', "launch() mutex unlocked"); - ptimer = PAUSETIME; if (opts) @@ -755,6 +747,16 @@ void die(int onsig) } if (cmd_run || ping_run || sched_run || disk_run || ibc_run) Syslog('+', "Not all threads stopped! Forced shutdown"); + if (cmd_run) + Syslog('+', "Thread cmd_run not responding"); + if (ping_run) + Syslog('+', "Thread ping_run not responding"); + if (sched_run) + Syslog('+', "Thread sched_run not responding"); + if (disk_run) + Syslog('+', "Thread disk_run not responding"); + if (ibc_run) + Syslog('+', "Thread ibc_run not responding"); else Syslog('+', "All threads stopped"); @@ -1240,9 +1242,12 @@ void *scheduler(void) running = checktasks(0); if (s_mailout && (!ptimer) && (!runtasktype(MBFIDO))) { - launch(TCFG.cmd_mailout, NULL, (char *)"mailout", MBFIDO); - running = checktasks(0); - s_mailout = FALSE; + if (! lock_ibc((char *)"scheduler 1")) { + launch(TCFG.cmd_mailout, NULL, (char *)"mailout", MBFIDO); + unlock_ibc((char *)"scheduler 1"); + running = checktasks(0); + s_mailout = FALSE; + } } if (s_mailin && (!ptimer) && (!runtasktype(MBFIDO))) { @@ -1256,23 +1261,32 @@ void *scheduler(void) if ((ipmailers + runtasktype(CM_ISDN) + runtasktype(CM_POTS)) == 0) { Syslog('i', "Mailin, no mailers running, start direct"); tosswait = TOSSWAIT_TIME; - launch(TCFG.cmd_mailin, NULL, (char *)"mailin", MBFIDO); - running = checktasks(0); - s_mailin = FALSE; + if (! lock_ibc((char *)"scheduler 2")) { + launch(TCFG.cmd_mailin, NULL, (char *)"mailin", MBFIDO); + unlock_ibc((char *)"scheduler 2"); + running = checktasks(0); + s_mailin = FALSE; + } } else { Syslog('i', "Mailin, tosswait=%d", tosswait); if (tosswait == 0) { - launch(TCFG.cmd_mailin, NULL, (char *)"mailin", MBFIDO); - running = checktasks(0); - s_mailin = FALSE; + if (! lock_ibc((char *)"scheduler 3")) { + launch(TCFG.cmd_mailin, NULL, (char *)"mailin", MBFIDO); + unlock_ibc((char *)"scheduler 3"); + running = checktasks(0); + s_mailin = FALSE; + } } } } if (s_newnews && (!ptimer) && (!runtasktype(MBFIDO))) { - launch(TCFG.cmd_newnews, NULL, (char *)"newnews", MBFIDO); - running = checktasks(0); - s_newnews = FALSE; + if (! lock_ibc((char *)"scheduler 4")) { + launch(TCFG.cmd_newnews, NULL, (char *)"newnews", MBFIDO); + unlock_ibc((char *)"scheduler 4"); + running = checktasks(0); + s_newnews = FALSE; + } } /* @@ -1282,12 +1296,24 @@ void *scheduler(void) * start them in parallel. */ if (s_index && (!ptimer) && (!running)) { - if (strlen(TCFG.cmd_mbindex1)) - launch(TCFG.cmd_mbindex1, NULL, (char *)"compiler 1", MBINDEX); - if (strlen(TCFG.cmd_mbindex2)) - launch(TCFG.cmd_mbindex2, NULL, (char *)"compiler 2", MBINDEX); - if (strlen(TCFG.cmd_mbindex3)) - launch(TCFG.cmd_mbindex3, NULL, (char *)"compiler 3", MBINDEX); + if (strlen(TCFG.cmd_mbindex1)) { + if (! lock_ibc((char *)"scheduler 5")) { + launch(TCFG.cmd_mbindex1, NULL, (char *)"compiler 1", MBINDEX); + unlock_ibc((char *)"scheduler 5"); + } + } + if (strlen(TCFG.cmd_mbindex2)) { + if (! lock_ibc((char *)"scheduler 6")) { + launch(TCFG.cmd_mbindex2, NULL, (char *)"compiler 2", MBINDEX); + unlock_ibc((char *)"scheduler 6"); + } + } + if (strlen(TCFG.cmd_mbindex3)) { + if (! lock_ibc((char *)"scheduler 7")) { + launch(TCFG.cmd_mbindex3, NULL, (char *)"compiler 3", MBINDEX); + unlock_ibc((char *)"scheduler 7"); + } + } running = checktasks(0); s_index = FALSE; } @@ -1297,7 +1323,10 @@ void *scheduler(void) * nothing else to do. */ if (s_msglink && (!ptimer) && (!running)) { - launch(TCFG.cmd_msglink, NULL, (char *)"msglink", MBFIDO); + if (! lock_ibc((char *)"scheduler 8")) { + launch(TCFG.cmd_msglink, NULL, (char *)"msglink", MBFIDO); + unlock_ibc((char *)"scheduler 8"); + } running = checktasks(0); s_msglink = FALSE; } @@ -1306,7 +1335,10 @@ void *scheduler(void) * Creating filerequest indexes, also only if nothing to do. */ if (s_reqindex && (!ptimer) && (!running)) { - launch(TCFG.cmd_reqindex, NULL, (char *)"reqindex", MBFILE); + if (! lock_ibc((char *)"scheduler 9")) { + launch(TCFG.cmd_reqindex, NULL, (char *)"reqindex", MBFILE); + unlock_ibc((char *)"scheduler 9"); + } running = checktasks(0); s_reqindex = FALSE; } @@ -1410,7 +1442,10 @@ void *scheduler(void) calllist[call_entry].addr.net, calllist[call_entry].addr.zone, calllist[call_entry].addr.domain); } - calllist[call_entry].taskpid = launch(cmd, opts, (char *)"mbcico", calllist[call_entry].callmode); + if (! lock_ibc((char *)"scheduler 10")) { + calllist[call_entry].taskpid = launch(cmd, opts, (char *)"mbcico", calllist[call_entry].callmode); + unlock_ibc((char *)"scheduler 10"); + } if (calllist[call_entry].taskpid) calllist[call_entry].calling = TRUE; running = checktasks(0); diff --git a/mbtask/taskibc.c b/mbtask/taskibc.c index 45252b7a..63852a7d 100644 --- a/mbtask/taskibc.c +++ b/mbtask/taskibc.c @@ -65,8 +65,6 @@ int is_locked = FALSE; /* Is mutex locked */ #define PING_PONG_LOG 1 - - pthread_mutex_t b_mutex = PTHREAD_MUTEX_INITIALIZER; @@ -80,6 +78,14 @@ static char *ncsstate[] = { }; +static char *mon[] = { + (char *)"Jan",(char *)"Feb",(char *)"Mar", + (char *)"Apr",(char *)"May",(char *)"Jun", + (char *)"Jul",(char *)"Aug",(char *)"Sep", + (char *)"Oct",(char *)"Nov",(char *)"Dec" +}; + + /* * Internal prototypes @@ -195,7 +201,8 @@ void dump_ncslist(void) srv_list *srv; usr_list *usrp; chn_list *chnp; - char temp1[128], temp2[128]; + char temp1[128], temp2[128], buf[21]; + struct tm ptm; if (!callchg && !srvchg && !usrchg && !chnchg && !banchg && !nickchg) return; @@ -223,7 +230,10 @@ void dump_ncslist(void) for (srv = servers; srv; srv = srv->next) { snprintf(temp1, 25, "%s", srv->server); snprintf(temp2, 25, "%s", srv->router); - Syslog('+', "IBC: %-25s %-25s %5d %5d %s", temp1, temp2, srv->hops, srv->users, rfcdate(srv->connected)); + localtime_r(&srv->connected, &ptm); + snprintf(buf, 21, "%02d-%s-%04d %02d:%02d:%02d", ptm.tm_mday, mon[ptm.tm_mon], ptm.tm_year+1900, + ptm.tm_hour, ptm.tm_min, ptm.tm_sec); + Syslog('+', "IBC: %-25s %-25s %5d %5d %s", temp1, temp2, srv->hops, srv->users, buf); } } else { Syslog('+', "IBC: Servers list is empty"); @@ -237,8 +247,11 @@ void dump_ncslist(void) for (usrp = users; usrp; usrp = usrp->next) { snprintf(temp1, 20, "%s", usrp->server); snprintf(temp2, 20, "%s", usrp->realname); + localtime_r(&usrp->connected, &ptm); + snprintf(buf, 21, "%02d-%s-%04d %02d:%02d:%02d", ptm.tm_mday, mon[ptm.tm_mon], ptm.tm_year+1900, + ptm.tm_hour, ptm.tm_min, ptm.tm_sec); Syslog('+', "IBC: %-20s %-20s %-9s %-13s %s %s", temp1, temp2, usrp->nick, usrp->channel, - usrp->sysop ? "yes":"no ", rfcdate(usrp->connected)); + usrp->sysop ? "yes":"no ", buf); } } else { Syslog('+', "IBC: Users list is empty"); @@ -250,8 +263,10 @@ void dump_ncslist(void) Syslog('+', "IBC: Channel Owner Topic Usr Created"); Syslog('+', "IBC: -------------------- --------- ----------------------------------- --- --------------------"); for (chnp = channels; chnp; chnp = chnp->next) { - Syslog('+', "IBC: %-20s %-9s %-35s %3d %s", chnp->name, chnp->owner, chnp->topic, - chnp->users, rfcdate(chnp->created)); + localtime_r(&chnp->created, &ptm); + snprintf(buf, 21, "%02d-%s-%04d %02d:%02d:%02d", ptm.tm_mday, mon[ptm.tm_mon], ptm.tm_year+1900, + ptm.tm_hour, ptm.tm_min, ptm.tm_sec); + Syslog('+', "IBC: %-20s %-9s %-35s %3d %s", chnp->name, chnp->owner, chnp->topic, chnp->users, buf); } } else { Syslog('+', "IBC: Channels list is empty"); diff --git a/mbtask/taskutil.c b/mbtask/taskutil.c index fdd9acc0..eae2edc0 100644 --- a/mbtask/taskutil.c +++ b/mbtask/taskutil.c @@ -4,7 +4,7 @@ * Purpose ...............: MBSE BBS Task Manager, utilities * ***************************************************************************** - * Copyright (C) 1997-2005 + * Copyright (C) 1997-2006 * * Michiel Broek FIDO: 2:280/2802 * Beekmansbos 10 @@ -48,57 +48,18 @@ static char *pbuff = NULL; static char *mon[] = { - (char *)"Jan",(char *)"Feb",(char *)"Mar", - (char *)"Apr",(char *)"May",(char *)"Jun", - (char *)"Jul",(char *)"Aug",(char *)"Sep", - (char *)"Oct",(char *)"Nov",(char *)"Dec" + (char *)"Jan",(char *)"Feb",(char *)"Mar", + (char *)"Apr",(char *)"May",(char *)"Jun", + (char *)"Jul",(char *)"Aug",(char *)"Sep", + (char *)"Oct",(char *)"Nov",(char *)"Dec" }; - /************************************************************************ * * Loging procedures. */ - -char *date(void); -char *date(void) -{ - struct tm ptm; - time_t now; - static char buf[21]; - - now = time(NULL); -#if defined(__OpenBSD__) - localtime_r(&now, &ptm); -#else - ptm = *localtime(&now); -#endif - snprintf(buf, 21, "%02d-%s-%04d %02d:%02d:%02d", ptm.tm_mday, mon[ptm.tm_mon], ptm.tm_year+1900, - ptm.tm_hour, ptm.tm_min, ptm.tm_sec); - return(buf); -} - - - -char *rfcdate(time_t now) -{ - struct tm ptm; - static char buf[21]; - -#if defined(__OpenBSD__) - localtime_r(&now, &ptm); -#else - ptm = *localtime(&now); -#endif - snprintf(buf, 21, "%02d-%s-%04d %02d:%02d:%02d", ptm.tm_mday, mon[ptm.tm_mon], ptm.tm_year+1900, - ptm.tm_hour, ptm.tm_min, ptm.tm_sec); - return(buf); -} - - - void WriteError(const char *format, ...) { char *outputstr; @@ -119,11 +80,13 @@ void WriteError(const char *format, ...) */ void Syslog(int grade, const char *format, ...) { - va_list va_ptr; - char outstr[1024]; - int oldmask, debug; - FILE *logfile = NULL, *debugfile; - char *logname = NULL, *debugname; + va_list va_ptr; + char outstr[1024], datestr[21]; + int oldmask, debug; + FILE *logfile = NULL, *debugfile; + char *logname = NULL, *debugname; + time_t now; + struct tm ptm; debug = isalpha(grade); va_start(va_ptr, format); @@ -165,16 +128,21 @@ void Syslog(int grade, const char *format, ...) return; } + now = time(NULL); + localtime_r(&now, &ptm); + snprintf(datestr, 21, "%02d-%s-%04d %02d:%02d:%02d", ptm.tm_mday, mon[ptm.tm_mon], ptm.tm_year+1900, + ptm.tm_hour, ptm.tm_min, ptm.tm_sec); + if (lcnt) { lcnt++; - fprintf(debugfile, "%c %s mbtask[%d] last message repeated %d times\n", lchr, date(), mypid, lcnt); + fprintf(debugfile, "%c %s mbtask[%d] last message repeated %d times\n", lchr, datestr, mypid, lcnt); if (!debug) - fprintf(logfile, "%c %s mbtask[%d] last message repeated %d times\n", lchr, date(), mypid, lcnt); + fprintf(logfile, "%c %s mbtask[%d] last message repeated %d times\n", lchr, datestr, mypid, lcnt); } lcnt = 0; if (!debug) { - fprintf(logfile, "%c %s mbtask[%d] ", grade, date(), mypid); + fprintf(logfile, "%c %s mbtask[%d] ", grade, datestr, mypid); fprintf(logfile, *outstr == '$' ? outstr+1 : outstr); if (*outstr == '$') fprintf(logfile, ": %s\n", strerror(errno)); @@ -188,7 +156,7 @@ void Syslog(int grade, const char *format, ...) free(logname); } - fprintf(debugfile, "%c %s mbtask[%d] ", grade, date(), mypid); + fprintf(debugfile, "%c %s mbtask[%d] ", grade, datestr, mypid); fprintf(debugfile, *outstr == '$' ? outstr+1 : outstr); if (*outstr == '$') fprintf(debugfile, ": %s\n", strerror(errno)); @@ -212,9 +180,12 @@ void Syslog(int grade, const char *format, ...) */ int ulog(char *fn, char *grade, char *prname, char *prpid, char *format) { - int i, oldmask; - FILE *fp; - + int i, oldmask; + FILE *fp; + time_t now; + struct tm ptm; + char datestr[21]; + oldmask = umask(066); fp = fopen(fn, "a"); umask(oldmask); @@ -224,7 +195,12 @@ int ulog(char *fn, char *grade, char *prname, char *prpid, char *format) return -1; } - fprintf(fp, "%s %s %s[%s] ", grade, date(), prname, prpid); + now = time(NULL); + localtime_r(&now, &ptm); + snprintf(datestr, 21, "%02d-%s-%04d %02d:%02d:%02d", ptm.tm_mday, mon[ptm.tm_mon], ptm.tm_year+1900, + ptm.tm_hour, ptm.tm_min, ptm.tm_sec); + + fprintf(fp, "%s %s %s[%s] ", grade, datestr, prname, prpid); for (i = 0; i < strlen(format); i++) { if (iscntrl(format[i])) { fputc('^', fp); diff --git a/mbtask/taskutil.h b/mbtask/taskutil.h index 2d9be291..ca9b9f2a 100644 --- a/mbtask/taskutil.h +++ b/mbtask/taskutil.h @@ -21,7 +21,6 @@ typedef struct _srv_auth { /* * Function prototypes */ -char *rfcdate(time_t); void WriteError(const char *, ...); void Syslog(int, const char *, ...); int ulog(char *, char *, char *, char *, char*);