Made logging multithread aware

This commit is contained in:
Michiel Broek 2006-01-29 16:47:32 +00:00
parent 3ff96b3cb2
commit e28a56e219
5 changed files with 120 additions and 94 deletions

View File

@ -5,6 +5,7 @@ v0.83.11 28-Jan-2006
mbtask: mbtask:
Added logging for possible detection of dialup IBC neighbour Added logging for possible detection of dialup IBC neighbour
address change. address change.
Made logging multithread aware.
v0.83.10 25-Jan-2006 - 28-Jan-2006 v0.83.10 25-Jan-2006 - 28-Jan-2006

View File

@ -465,11 +465,6 @@ pid_t launch(char *cmd, char *opts, char *name, int tasktype)
return 0; return 0;
} }
if (lock_ibc((char *)"launch")) {
return 0;
}
Syslog('r', "launch() mutex locked");
pid = fork(); pid = fork();
switch (pid) { switch (pid) {
case -1: 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; ptimer = PAUSETIME;
if (opts) if (opts)
@ -755,6 +747,16 @@ void die(int onsig)
} }
if (cmd_run || ping_run || sched_run || disk_run || ibc_run) if (cmd_run || ping_run || sched_run || disk_run || ibc_run)
Syslog('+', "Not all threads stopped! Forced shutdown"); 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 else
Syslog('+', "All threads stopped"); Syslog('+', "All threads stopped");
@ -1240,9 +1242,12 @@ void *scheduler(void)
running = checktasks(0); running = checktasks(0);
if (s_mailout && (!ptimer) && (!runtasktype(MBFIDO))) { if (s_mailout && (!ptimer) && (!runtasktype(MBFIDO))) {
launch(TCFG.cmd_mailout, NULL, (char *)"mailout", MBFIDO); if (! lock_ibc((char *)"scheduler 1")) {
running = checktasks(0); launch(TCFG.cmd_mailout, NULL, (char *)"mailout", MBFIDO);
s_mailout = FALSE; unlock_ibc((char *)"scheduler 1");
running = checktasks(0);
s_mailout = FALSE;
}
} }
if (s_mailin && (!ptimer) && (!runtasktype(MBFIDO))) { if (s_mailin && (!ptimer) && (!runtasktype(MBFIDO))) {
@ -1256,23 +1261,32 @@ void *scheduler(void)
if ((ipmailers + runtasktype(CM_ISDN) + runtasktype(CM_POTS)) == 0) { if ((ipmailers + runtasktype(CM_ISDN) + runtasktype(CM_POTS)) == 0) {
Syslog('i', "Mailin, no mailers running, start direct"); Syslog('i', "Mailin, no mailers running, start direct");
tosswait = TOSSWAIT_TIME; tosswait = TOSSWAIT_TIME;
launch(TCFG.cmd_mailin, NULL, (char *)"mailin", MBFIDO); if (! lock_ibc((char *)"scheduler 2")) {
running = checktasks(0); launch(TCFG.cmd_mailin, NULL, (char *)"mailin", MBFIDO);
s_mailin = FALSE; unlock_ibc((char *)"scheduler 2");
running = checktasks(0);
s_mailin = FALSE;
}
} else { } else {
Syslog('i', "Mailin, tosswait=%d", tosswait); Syslog('i', "Mailin, tosswait=%d", tosswait);
if (tosswait == 0) { if (tosswait == 0) {
launch(TCFG.cmd_mailin, NULL, (char *)"mailin", MBFIDO); if (! lock_ibc((char *)"scheduler 3")) {
running = checktasks(0); launch(TCFG.cmd_mailin, NULL, (char *)"mailin", MBFIDO);
s_mailin = FALSE; unlock_ibc((char *)"scheduler 3");
running = checktasks(0);
s_mailin = FALSE;
}
} }
} }
} }
if (s_newnews && (!ptimer) && (!runtasktype(MBFIDO))) { if (s_newnews && (!ptimer) && (!runtasktype(MBFIDO))) {
launch(TCFG.cmd_newnews, NULL, (char *)"newnews", MBFIDO); if (! lock_ibc((char *)"scheduler 4")) {
running = checktasks(0); launch(TCFG.cmd_newnews, NULL, (char *)"newnews", MBFIDO);
s_newnews = FALSE; unlock_ibc((char *)"scheduler 4");
running = checktasks(0);
s_newnews = FALSE;
}
} }
/* /*
@ -1282,12 +1296,24 @@ void *scheduler(void)
* start them in parallel. * start them in parallel.
*/ */
if (s_index && (!ptimer) && (!running)) { if (s_index && (!ptimer) && (!running)) {
if (strlen(TCFG.cmd_mbindex1)) if (strlen(TCFG.cmd_mbindex1)) {
launch(TCFG.cmd_mbindex1, NULL, (char *)"compiler 1", MBINDEX); if (! lock_ibc((char *)"scheduler 5")) {
if (strlen(TCFG.cmd_mbindex2)) launch(TCFG.cmd_mbindex1, NULL, (char *)"compiler 1", MBINDEX);
launch(TCFG.cmd_mbindex2, NULL, (char *)"compiler 2", MBINDEX); unlock_ibc((char *)"scheduler 5");
if (strlen(TCFG.cmd_mbindex3)) }
launch(TCFG.cmd_mbindex3, NULL, (char *)"compiler 3", MBINDEX); }
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); running = checktasks(0);
s_index = FALSE; s_index = FALSE;
} }
@ -1297,7 +1323,10 @@ void *scheduler(void)
* nothing else to do. * nothing else to do.
*/ */
if (s_msglink && (!ptimer) && (!running)) { 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); running = checktasks(0);
s_msglink = FALSE; s_msglink = FALSE;
} }
@ -1306,7 +1335,10 @@ void *scheduler(void)
* Creating filerequest indexes, also only if nothing to do. * Creating filerequest indexes, also only if nothing to do.
*/ */
if (s_reqindex && (!ptimer) && (!running)) { 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); running = checktasks(0);
s_reqindex = FALSE; s_reqindex = FALSE;
} }
@ -1410,7 +1442,10 @@ void *scheduler(void)
calllist[call_entry].addr.net, calllist[call_entry].addr.net,
calllist[call_entry].addr.zone, calllist[call_entry].addr.domain); 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) if (calllist[call_entry].taskpid)
calllist[call_entry].calling = TRUE; calllist[call_entry].calling = TRUE;
running = checktasks(0); running = checktasks(0);

View File

@ -65,8 +65,6 @@ int is_locked = FALSE; /* Is mutex locked */
#define PING_PONG_LOG 1 #define PING_PONG_LOG 1
pthread_mutex_t b_mutex = PTHREAD_MUTEX_INITIALIZER; 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 * Internal prototypes
@ -195,7 +201,8 @@ void dump_ncslist(void)
srv_list *srv; srv_list *srv;
usr_list *usrp; usr_list *usrp;
chn_list *chnp; 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) if (!callchg && !srvchg && !usrchg && !chnchg && !banchg && !nickchg)
return; return;
@ -223,7 +230,10 @@ void dump_ncslist(void)
for (srv = servers; srv; srv = srv->next) { for (srv = servers; srv; srv = srv->next) {
snprintf(temp1, 25, "%s", srv->server); snprintf(temp1, 25, "%s", srv->server);
snprintf(temp2, 25, "%s", srv->router); 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 { } else {
Syslog('+', "IBC: Servers list is empty"); Syslog('+', "IBC: Servers list is empty");
@ -237,8 +247,11 @@ void dump_ncslist(void)
for (usrp = users; usrp; usrp = usrp->next) { for (usrp = users; usrp; usrp = usrp->next) {
snprintf(temp1, 20, "%s", usrp->server); snprintf(temp1, 20, "%s", usrp->server);
snprintf(temp2, 20, "%s", usrp->realname); 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, 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 { } else {
Syslog('+', "IBC: Users list is empty"); Syslog('+', "IBC: Users list is empty");
@ -250,8 +263,10 @@ void dump_ncslist(void)
Syslog('+', "IBC: Channel Owner Topic Usr Created"); Syslog('+', "IBC: Channel Owner Topic Usr Created");
Syslog('+', "IBC: -------------------- --------- ----------------------------------- --- --------------------"); Syslog('+', "IBC: -------------------- --------- ----------------------------------- --- --------------------");
for (chnp = channels; chnp; chnp = chnp->next) { for (chnp = channels; chnp; chnp = chnp->next) {
Syslog('+', "IBC: %-20s %-9s %-35s %3d %s", chnp->name, chnp->owner, chnp->topic, localtime_r(&chnp->created, &ptm);
chnp->users, rfcdate(chnp->created)); 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 { } else {
Syslog('+', "IBC: Channels list is empty"); Syslog('+', "IBC: Channels list is empty");

View File

@ -4,7 +4,7 @@
* Purpose ...............: MBSE BBS Task Manager, utilities * Purpose ...............: MBSE BBS Task Manager, utilities
* *
***************************************************************************** *****************************************************************************
* Copyright (C) 1997-2005 * Copyright (C) 1997-2006
* *
* Michiel Broek FIDO: 2:280/2802 * Michiel Broek FIDO: 2:280/2802
* Beekmansbos 10 * Beekmansbos 10
@ -48,57 +48,18 @@ static char *pbuff = NULL;
static char *mon[] = { static char *mon[] = {
(char *)"Jan",(char *)"Feb",(char *)"Mar", (char *)"Jan",(char *)"Feb",(char *)"Mar",
(char *)"Apr",(char *)"May",(char *)"Jun", (char *)"Apr",(char *)"May",(char *)"Jun",
(char *)"Jul",(char *)"Aug",(char *)"Sep", (char *)"Jul",(char *)"Aug",(char *)"Sep",
(char *)"Oct",(char *)"Nov",(char *)"Dec" (char *)"Oct",(char *)"Nov",(char *)"Dec"
}; };
/************************************************************************ /************************************************************************
* *
* Loging procedures. * 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, ...) void WriteError(const char *format, ...)
{ {
char *outputstr; char *outputstr;
@ -119,11 +80,13 @@ void WriteError(const char *format, ...)
*/ */
void Syslog(int grade, const char *format, ...) void Syslog(int grade, const char *format, ...)
{ {
va_list va_ptr; va_list va_ptr;
char outstr[1024]; char outstr[1024], datestr[21];
int oldmask, debug; int oldmask, debug;
FILE *logfile = NULL, *debugfile; FILE *logfile = NULL, *debugfile;
char *logname = NULL, *debugname; char *logname = NULL, *debugname;
time_t now;
struct tm ptm;
debug = isalpha(grade); debug = isalpha(grade);
va_start(va_ptr, format); va_start(va_ptr, format);
@ -165,16 +128,21 @@ void Syslog(int grade, const char *format, ...)
return; 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) { if (lcnt) {
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) 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; lcnt = 0;
if (!debug) { 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); fprintf(logfile, *outstr == '$' ? outstr+1 : outstr);
if (*outstr == '$') if (*outstr == '$')
fprintf(logfile, ": %s\n", strerror(errno)); fprintf(logfile, ": %s\n", strerror(errno));
@ -188,7 +156,7 @@ void Syslog(int grade, const char *format, ...)
free(logname); 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); fprintf(debugfile, *outstr == '$' ? outstr+1 : outstr);
if (*outstr == '$') if (*outstr == '$')
fprintf(debugfile, ": %s\n", strerror(errno)); 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 ulog(char *fn, char *grade, char *prname, char *prpid, char *format)
{ {
int i, oldmask; int i, oldmask;
FILE *fp; FILE *fp;
time_t now;
struct tm ptm;
char datestr[21];
oldmask = umask(066); oldmask = umask(066);
fp = fopen(fn, "a"); fp = fopen(fn, "a");
umask(oldmask); umask(oldmask);
@ -224,7 +195,12 @@ int ulog(char *fn, char *grade, char *prname, char *prpid, char *format)
return -1; 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++) { for (i = 0; i < strlen(format); i++) {
if (iscntrl(format[i])) { if (iscntrl(format[i])) {
fputc('^', fp); fputc('^', fp);

View File

@ -21,7 +21,6 @@ typedef struct _srv_auth {
/* /*
* Function prototypes * Function prototypes
*/ */
char *rfcdate(time_t);
void WriteError(const char *, ...); void WriteError(const char *, ...);
void Syslog(int, const char *, ...); void Syslog(int, const char *, ...);
int ulog(char *, char *, char *, char *, char*); int ulog(char *, char *, char *, char *, char*);