Index: ossp-pkg/fsl/Makefile.in RCS File: /v/ossp/cvs/ossp-pkg/fsl/Makefile.in,v rcsdiff -q -kk '-r1.13' '-r1.14' -u '/v/ossp/cvs/ossp-pkg/fsl/Makefile.in,v' 2>/dev/null --- Makefile.in 2003/01/06 16:41:21 1.13 +++ Makefile.in 2003/05/20 15:47:23 1.14 @@ -115,13 +115,15 @@ test: check check: $(TST_NAME) - @$(RM) fsl_test.debug >/dev/null 2>&1 || true; \ - $(RM) fsl_test.syslog >/dev/null 2>&1 || true; \ + @[ -f fsl_test.debug ] && $(RM) fsl_test.debug || true + @[ -f fsl_test.syslog ] && $(RM) fsl_test.syslog || true + @true && \ FSL_CFGDIR=.; export FSL_CFGDIR; \ FSL_PREFIX=fsl_test.cfg; export FSL_PREFIX; \ FSL_DEBUG="trace: file(path=fsl_test.debug)"; export FSL_DEBUG; \ $(LIBTOOL) --mode=execute ./$(TST_NAME) - @echo "fsl_test.syslog:"; cat fsl_test.syslog + @echo "fsl_test.syslog:"; if [ -s fsl_test.syslog ]; then cat fsl_test.syslog; else echo " ***EMPTY***"; fi + #echo "fsl_test.debug:"; if [ -s fsl_test.debug ]; then cat fsl_test.debug; else echo " ***EMPTY***"; fi install: all $(SHTOOL) mkdir -f -p -m 755 $(DESTDIR)$(prefix) Index: ossp-pkg/fsl/fsl.c RCS File: /v/ossp/cvs/ossp-pkg/fsl/fsl.c,v rcsdiff -q -kk '-r1.56' '-r1.57' -u '/v/ossp/cvs/ossp-pkg/fsl/fsl.c,v' 2>/dev/null --- fsl.c 2003/01/06 16:41:21 1.56 +++ fsl.c 2003/05/20 15:47:23 1.57 @@ -177,8 +177,6 @@ /* internal global context structure */ static struct { - l2_env_t *l2_fslenv; - l2_channel_t *l2_fslnch; l2_env_t *l2_env; l2_channel_t *l2_nch; levelmap_t *levelmap; @@ -186,40 +184,167 @@ int logopt; int delayopen; int triedopenlog; - int triedopenfsldebug; - int openfsldebugpermanenterror; + /* fsl debugging */ + l2_env_t *fsldebug_l2_env; + l2_channel_t *fsldebug_l2_nch; + int fsldebug_transientproblem; + int fsldebug_permanentproblem; } ctx = { NULL, NULL, NULL, - NULL, - NULL, LOG_UPTO(LOG_DEBUG), 0, + TRUE, FALSE, - FALSE, + /* fsl debugging */ + NULL, + NULL, FALSE, FALSE }; -/* internal debugging function */ +/* internal debugging prototypes */ +static void fsldebugcreate (void); +static void fsldebug (l2_level_t, const char *, ...); +static int fsldebugl2 (l2_level_t, const char *, va_list); +static int fsldebugf2 (l2_level_t, const char *, va_list); +static void fsldebugdestroy(void); + +/* internal debugging functions */ +static void fsldebugcreate() +{ + int rc = FSL_OK; + char *argl2spec; + l2_result_t l2rv; + char *cp; /* scratch variable */ + l2_channel_t *ch; /* scratch variable */ + + /* identify previous fault and avoid repetition */ + if (ctx.fsldebug_permanentproblem || ctx.fsldebug_transientproblem) + return; + + /* create OSSP l2 environment for fsl itself (internal logging) */ + if ((argl2spec = getenv("FSL_DEBUG")) == NULL) + argl2spec = FSL_DEBUG; + if (strlen(argl2spec) > 0) { + if ((l2rv = l2_env_create(&ctx.fsldebug_l2_env)) != L2_OK) { + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: failed to create L2 environment (%d) for fsl", l2rv); CU(FSL_ERR_INT); } + if ((l2rv = l2_env_levels(ctx.fsldebug_l2_env, L2_LEVEL_ALL, L2_LEVEL_NONE)) != L2_OK) { + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to set global logging level defaults %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } + if ((l2rv = l2_env_formatter(ctx.fsldebug_l2_env, 'D', l2_util_fmt_dump, NULL)) != L2_OK) { + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to register dump formatter %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } + if ((l2rv = l2_env_formatter(ctx.fsldebug_l2_env, 'S', l2_util_fmt_string, NULL)) != L2_OK) { + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to register string formatter %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } + if ((l2rv = l2_env_formatter(ctx.fsldebug_l2_env, 'm', l2_util_fmt_errno, NULL)) != L2_OK) { + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to register errno formatter %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } + if ((l2rv = l2_channel_create(&ctx.fsldebug_l2_nch, ctx.fsldebug_l2_env, "noop")) != L2_OK) { + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to create noop channel; %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } + if ((l2rv = l2_spec(&ch, ctx.fsldebug_l2_env, "%s", argl2spec)) != L2_OK) { + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to create stream from spec %s(%d) for fsl", cp, l2rv); + if (l2rv == L2_ERR_ARG) + CU(FSL_ERR_ARG); + else + CU(FSL_ERR_INT); + } + if ((l2rv = l2_channel_link(ctx.fsldebug_l2_nch, L2_LINK_CHILD, ch, NULL)) != L2_OK) { + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to link child channel %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } + if ((~ctx.logopt & LOG_NDELAY) && (ctx.delayopen == TRUE)) { + fsldebug(L2_LEVEL_ERROR, "openlog: LOG_NDELAY unused forces debugging to use stealth mode until first syslog"); } + else { + if ((l2rv = l2_channel_open(ctx.fsldebug_l2_nch)) != L2_OK) { + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to open channel stream %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } + } + } +CUS: + if (rc == FSL_ERR_ARG) + ctx.fsldebug_permanentproblem = TRUE; + if (rc != FSL_OK) + fsldebugdestroy(); +} + static void fsldebug(l2_level_t level, const char *message, ...) { va_list ap; - char cp[8]; va_start(ap, message); - /* note that a L2_ERR_USE is only returned by l2_channel_vlog() if the channel is not yet open */ - if (ctx.l2_fslnch == NULL || (l2_channel_vlog(ctx.l2_fslnch, level, message, ap) == L2_ERR_USE)) - if (level & L2_LEVEL_UPTO(L2_LEVEL_ERROR)) { - fprintf( stderr, "%s: ", l2_util_l2s(cp, sizeof(cp), '\0', level) == L2_OK ? cp[0]&=0xDF, cp : "Log"); - vfprintf(stderr, message, ap); - fprintf( stderr, "\n"); - } + fsldebugl2(level, message, ap) || fsldebugf2(level, message, ap); va_end(ap); return; } +static int fsldebugl2(l2_level_t level, const char *message, va_list ap) +{ + int rc = FALSE; /* the pessimist */ + l2_result_t l2rv; + char *cp; + + /* identify previous fault and avoid repetition */ + if (ctx.fsldebug_permanentproblem || ctx.fsldebug_transientproblem) + return rc; + + /* nothing has been prepared, so do it now */ + if (ctx.fsldebug_l2_nch == NULL) + fsldebugcreate(); + + /* identify previous fault and avoid repetition */ + if (ctx.fsldebug_permanentproblem || ctx.fsldebug_transientproblem) + return rc; + + /* preparation failed */ + if (ctx.fsldebug_l2_nch == NULL) + return rc; + + /* try logging, L2_ERR_USE only occurs if channel is not yet open */ + if ((l2rv = l2_channel_vlog(ctx.fsldebug_l2_nch, level, message, ap)) == L2_ERR_USE) { + if ((l2rv = l2_channel_open(ctx.fsldebug_l2_nch)) != L2_OK) { + ctx.fsldebug_transientproblem = TRUE; /* avoid loop from fsldebug() in next line */ + cp = l2_env_strerror(ctx.fsldebug_l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to open channel stream %s(%d) for fsl", cp, l2rv); + ctx.fsldebug_transientproblem = FALSE; /* opening the channel might work at next attempt */ + return rc; + } + l2rv = l2_channel_vlog(ctx.fsldebug_l2_nch, level, message, ap); + } + + if (l2rv == L2_OK) + rc = TRUE; + + /* if openlog(3) "did not request LOG_NDELAY" aka "did request delay" (~ctx.logopt & LOG_NDELAY), + * until a syslog(3) was tried (ctx.delayopen == TRUE), operate in stealth mode by closing channel + */ + if ((~ctx.logopt & LOG_NDELAY) && (ctx.delayopen == TRUE)) + (void)l2_channel_close(ctx.fsldebug_l2_nch); + + return rc; +} + +static int fsldebugf2(l2_level_t level, const char *message, va_list ap) +{ + int rc = TRUE; /* the optimist */ + char cp[8]; + + if (level & L2_LEVEL_UPTO(L2_LEVEL_ERROR)) { + fprintf( stderr, "%s: ", l2_util_l2s(cp, sizeof(cp), '\0', level) == L2_OK ? cp[0]&=0xDF, cp : "Log"); + vfprintf(stderr, message, ap); + fprintf( stderr, "\n"); + } + return rc; +} + +static void fsldebugdestroy() +{ + if (ctx.fsldebug_l2_nch != NULL) { + l2_channel_destroy(ctx.fsldebug_l2_nch); + ctx.fsldebug_l2_nch = NULL; + } + if (ctx.fsldebug_l2_env != NULL) { + l2_env_destroy(ctx.fsldebug_l2_env); + ctx.fsldebug_l2_env = NULL; + } + ctx.fsldebug_transientproblem = FALSE; + /* fsldebug_permanentproblem kept */ +} + /* append contents of a file to buffer */ static fsl_rc_t appendfiletobuffer(buf_t *buffer, const char *filename) { @@ -613,68 +738,6 @@ return rc; } -static void closefsllog() -{ - if (ctx.l2_fslnch != NULL) { - l2_channel_destroy(ctx.l2_fslnch); - ctx.l2_fslnch = NULL; - } - if (ctx.l2_fslenv != NULL) { - l2_env_destroy(ctx.l2_fslenv); - ctx.l2_fslenv = NULL; - } - ctx.triedopenfsldebug = FALSE; -} - -static void openfsldebug() -{ - int rc = FSL_OK; - char *argl2spec; - l2_result_t l2rv; - char *cp; /* scratch variable */ - l2_channel_t *ch; /* scratch variable */ - - if (ctx.triedopenfsldebug || ctx.openfsldebugpermanenterror) - return; - - /* properly prepare for repeated execution */ - ctx.triedopenfsldebug = TRUE; - - /* create OSSP l2 environment for fsl itself (internal logging) */ - if ((argl2spec = getenv("FSL_DEBUG")) == NULL) - argl2spec = FSL_DEBUG; - if (strlen(argl2spec) > 0) { - if ((l2rv = l2_env_create(&ctx.l2_fslenv)) != L2_OK) { - cp = l2_env_strerror(ctx.l2_fslenv, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: failed to create L2 environment (%d) for fsl", l2rv); CU(FSL_ERR_INT); } - if ((l2rv = l2_env_levels(ctx.l2_fslenv, L2_LEVEL_ALL, L2_LEVEL_NONE)) != L2_OK) { - cp = l2_env_strerror(ctx.l2_fslenv, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to set global logging level defaults %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } - if ((l2rv = l2_env_formatter(ctx.l2_fslenv, 'D', l2_util_fmt_dump, NULL)) != L2_OK) { - cp = l2_env_strerror(ctx.l2_fslenv, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to register dump formatter %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } - if ((l2rv = l2_env_formatter(ctx.l2_fslenv, 'S', l2_util_fmt_string, NULL)) != L2_OK) { - cp = l2_env_strerror(ctx.l2_fslenv, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to register string formatter %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } - if ((l2rv = l2_env_formatter(ctx.l2_fslenv, 'm', l2_util_fmt_errno, NULL)) != L2_OK) { - cp = l2_env_strerror(ctx.l2_fslenv, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to register errno formatter %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } - if ((l2rv = l2_channel_create(&ctx.l2_fslnch, ctx.l2_fslenv, "noop")) != L2_OK) { - cp = l2_env_strerror(ctx.l2_fslenv, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to create noop channel; %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } - if ((l2rv = l2_spec(&ch, ctx.l2_fslenv, "%s", argl2spec)) != L2_OK) { - cp = l2_env_strerror(ctx.l2_fslenv, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to create stream from spec %s(%d) for fsl", cp, l2rv); - if (l2rv == L2_ERR_ARG) - CU(FSL_ERR_ARG); - else - CU(FSL_ERR_INT); - } - if ((l2rv = l2_channel_link(ctx.l2_fslnch, L2_LINK_CHILD, ch, NULL)) != L2_OK) { - cp = l2_env_strerror(ctx.l2_fslenv, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to link child channel %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } - if ((l2rv = l2_channel_open(ctx.l2_fslnch)) != L2_OK) { - cp = l2_env_strerror(ctx.l2_fslenv, l2rv); fsldebug(L2_LEVEL_ERROR, "openlog: logging failed to open channel stream %s(%d) for fsl", cp, l2rv); CU(FSL_ERR_INT); } - } -CUS: - if (rc != FSL_OK) - closefsllog(); - if (rc == FSL_ERR_ARG) - ctx.openfsldebugpermanenterror = TRUE; -} - /* POSIX API function openlog(3) */ void openlog(const char *ident, int logopt, int facility) { @@ -702,21 +765,24 @@ closelog(); ctx.triedopenlog = TRUE; - /* create OSSP l2 environment for fsl itself (internal logging) */ - openfsldebug(); + /* remember logopt */ + ctx.logopt = logopt; + + /* handle delayed open logopt value */ + if (ctx.logopt & LOG_NDELAY) + ctx.delayopen = FALSE; /* tracing */ - fsldebug(L2_LEVEL_TRACE, "openlog() ident=\"%s\", logopt=0x%.8lx, facility=0x%.8lx; caught by %s", ident, logopt, facility, fsl_version.v_gnu); + fsldebug(L2_LEVEL_TRACE, "fsl in openlog(3) ident=%s%s%s, logopt=0x%.8lx, facility=0x%.8lx; caught by %s", ident == NULL ? "" : "\"", ident == NULL ? "NULL" : ident, ident == NULL ? "" : "\"" , logopt, facility, fsl_version.v_gnu); - /* remember logopt and handle unsupported values */ - ctx.logopt = logopt; - if (logopt & LOG_CONS) + /* handle unsupported logopt values */ + if (ctx.logopt & LOG_CONS) fsldebug(L2_LEVEL_WARNING, "openlog: ignore unsupported LOG_CONS"); #ifdef LOG_PERROR - if (logopt & LOG_PERROR) + if (ctx.logopt & LOG_PERROR) fsldebug(L2_LEVEL_WARNING, "openlog: ignore unsupported LOG_PERROR (use OSSP l2 channel \"fd(filedescriptor=2)\" to emulate)"); #endif - if (logopt & LOG_PID) + if (ctx.logopt & LOG_PID) fsldebug(L2_LEVEL_WARNING, "openlog: ignore unsupported LOG_PID (use OSSP l2 formatter %%P in prefix channel to emulate)"); /* create default sysloglevel to l2_level mapping */ @@ -782,8 +848,7 @@ fsldebug(L2_LEVEL_ERROR, "openlog: processcfg() failed with an unrecoverable error (%d)", rv); CU(1); } /* open logging now or prepare for delayed open */ - if (logopt & LOG_NDELAY) { - ctx.delayopen = TRUE; + if (~logopt & LOG_NDELAY) { fsldebug(L2_LEVEL_TRACE, "openlog: logopt LOG_NDELAY delays open of L2 channel tree until first message is being logged"); } else { @@ -811,8 +876,10 @@ /* faked POSIX API function closelog(3) */ void closelog(void) { - fsldebug(L2_LEVEL_TRACE, "closelog()"); - closefsllog(); + /* tracing */ + fsldebug(L2_LEVEL_TRACE, "fsl in closelog(3)"); + + fsldebugdestroy(); if (ctx.l2_nch != NULL) { l2_channel_destroy(ctx.l2_nch); ctx.l2_nch = NULL; @@ -827,8 +894,9 @@ } ctx.maskpri = LOG_UPTO(LOG_DEBUG); ctx.logopt = 0; - ctx.delayopen = FALSE; + ctx.delayopen = TRUE; ctx.triedopenlog = FALSE; + return; } @@ -837,7 +905,9 @@ { int oldmask; - fsldebug(L2_LEVEL_TRACE, "setlogmask() maskpri=0x%.8lx", maskpri); + /* tracing */ + fsldebug(L2_LEVEL_TRACE, "fsl in setlogmask(3) maskpri=0x%.8lx", maskpri); + oldmask = ctx.maskpri; if (maskpri != 0) ctx.maskpri = maskpri; @@ -849,6 +919,9 @@ { va_list args; + /* tracing */ + fsldebug(L2_LEVEL_TRACE, "fsl in syslog(3); go ahead using vsyslog(3)"); + /* wrap around vsyslog(3) */ va_start(args, message); vsyslog(priority, message, args); @@ -868,7 +941,10 @@ l2_result_t l2rv; char *cp; - /* check for previous omitted attempt of initialization */ + /* tracing */ + fsldebug(L2_LEVEL_TRACE, "fsl in vsyslog(3) fmt=%s%s%s ...", fmt == NULL ? "" : "\"", fmt == NULL ? "NULL" : fmt, fmt == NULL ? "" : "\""); + + /* check for omitted openlog(3) */ if (ctx.l2_nch == NULL && !ctx.triedopenlog) openlog("fsl", 0, LOG_SYSLOG); @@ -877,7 +953,7 @@ return; /* check for delayed open */ - if ((ctx.logopt & LOG_NDELAY) && (ctx.delayopen == TRUE)) { + if ((~ctx.logopt & LOG_NDELAY) && (ctx.delayopen == TRUE)) { if ((l2rv = l2_channel_open(ctx.l2_nch)) != L2_OK) { cp = l2_env_strerror(ctx.l2_env, l2rv); fsldebug(L2_LEVEL_ERROR, "vsyslog: logging failed to open channel stream %s(%d) delayed", cp, l2rv); closelog(); Index: ossp-pkg/fsl/fsl_test.c RCS File: /v/ossp/cvs/ossp-pkg/fsl/fsl_test.c,v rcsdiff -q -kk '-r1.4' '-r1.5' -u '/v/ossp/cvs/ossp-pkg/fsl/fsl_test.c,v' 2>/dev/null --- fsl_test.c 2002/07/24 15:29:01 1.4 +++ fsl_test.c 2003/05/20 15:47:23 1.5 @@ -1,14 +1,55 @@ #include #include +#include /* open(2) */ +#include /* close(2) */ +#include /* exit(3) */ + +static void pexit(const char *msg, int rc) +{ + fprintf(stderr, "ERROR: %s\n", msg); + exit(rc); +} + +static int tryfd(void) +{ + int fd; + + if ((fd = open("/dev/null", O_RDONLY)) == -1) + pexit("internal - cannot open /dev/null for reading", 1); + if (close(fd) == -1) + pexit("internal - cannot close(2)", 1); + return fd; +} int main(int argc, char *argv[]) { - syslog(LOG_INFO, "Connection from host %s", "foo.bar.dom"); + int fd1, fd2; + + fd1 = tryfd(); + setlogmask(LOG_UPTO(LOG_ERR)); + openlog("mail", LOG_PID, LOG_LOCAL0); /* this must not consume a filedescriptor; LOG_NDELAY and break it */ + setlogmask(LOG_UPTO(LOG_ERR)); + fd2 = tryfd(); + if (fd1 != fd2) + pexit("testsuite - filedescriptor allocated where it should not", 2); + closelog(); + + fd1 = tryfd(); + openlog("mail", LOG_PID, LOG_LOCAL1); + if (fd1 != tryfd()) + pexit("testsuite - filedescriptor allocated where it should not", 2); + setlogmask(LOG_UPTO(LOG_ERR)); + if (fd1 != tryfd()) + pexit("testsuite - filedescriptor allocated where it should not", 2); + syslog(LOG_ALERT, "one"); + syslog(LOG_ALERT, "two"); + closelog(); + openlog("mail", LOG_PID|LOG_NDELAY, LOG_LOCAL0); - syslog(LOG_ALERT, "who: internal error 23\n"); + syslog(LOG_ALERT, "who: internal 23\n"); setlogmask(LOG_UPTO(LOG_ERR)); - syslog(LOG_INFO|LOG_LOCAL2, "foobar error: %m"); + syslog(LOG_INFO|LOG_LOCAL2, "foobar: %m"); syslog(LOG_EMERG, "syslogging LOG_EMERG %d", LOG_EMERG ); syslog(LOG_ALERT, "syslogging LOG_ALERT %d", LOG_ALERT ); syslog(LOG_CRIT, "syslogging LOG_CRIT %d", LOG_CRIT ); @@ -18,6 +59,7 @@ syslog(LOG_INFO, "syslogging LOG_INFO %d", LOG_INFO ); syslog(LOG_DEBUG, "syslogging LOG_DEBUG %d", LOG_DEBUG ); closelog(); + return 0; }