/* * COPYRIGHT (c) International Business Machines Corp. 2001-2017 * * This program is provided under the terms of the Common Public License, * version 1.0 (CPL-1.0). Any use, reproduction or distribution for this * software constitutes recipient's acceptance of CPL-1.0 terms which can be * found in the file LICENSE file or at * https://opensource.org/licenses/cpl1.0.php */ #include #include #include #include #include #include #include #include "log.h" #include "err.h" #include "slotmgr.h" #include "pkcsslotd.h" #define DEFAULT_PROGRAM_NAME "Program" #ifndef PROGRAM_NAME #define PROGRAM_NAME DEFAULT_PROGRAM_NAME #endif /* PROGRAM_NAME */ #ifdef DEV #ifndef DEFAULT_LOG_FILE #define DEFAULT_LOG_FILE "/tmp/" ## PROGRAM_NAME ## ".log" #endif /* DEFAULT_LOG_FILE */ #else /* production build */ #ifndef DEFAULT_LOG_FILE #define DEFAULT_LOG_FILE NULL #endif /* DEFAULT_LOG_FILE */ #endif /* DEV */ #ifndef LOG_FILE #define LOG_FILE DEFAULT_LOG_FILE #endif /* LOG_FILE */ #ifndef DEFAULT_DEBUG_LEVEL /********************* DEFAULT_DEBUG_LEVEL is generally defined in another file (pkcsslotd.h?) The #defines here generally won't change much. *********************/ #ifdef DEV #define DEFAULT_DEBUG_LEVEL DEBUG_LEVEL0 #else #define DEFAULT_DEBUG_LEVEL DEBUG_NONE #endif /* DEFAULT_DEBUG_LEVEL */ #endif /* DEFAULT_DEBUG_LEVEL */ static u_int32 DefaultLogOption = (LOG_CONS | LOG_NOWAIT | LOG_ODELAY | LOG_PID); static BOOL Initialized = FALSE; static BOOL LoggingInitialized = FALSE; static u_int32 SysDebugLevel = DEFAULT_DEBUG_LEVEL; static char *ProgramName = PROGRAM_NAME; static LoggingFacilityInfo LogInfo[MAX_LOGGING_FACILITIES]; static LogHandle hLogDebug; static LogHandle hLogErr; static LogHandle hLogLog; static LogHandle hLogTrace; static LogHandle hLogWarn; static LogHandle hLogInfo; static LoggingFacility SystemLogFacilities[] = { {" DEBUG", &hLogDebug, LOG_FILE, TRUE, LOG_DEBUG}, {" INFO", &hLogInfo, LOG_FILE, TRUE, LOG_INFO}, {" TRACE", &hLogTrace, LOG_FILE, TRUE, LOG_INFO}, {" LOG", &hLogLog, LOG_FILE, TRUE, LOG_NOTICE}, {"WARNING", &hLogWarn, LOG_FILE, TRUE, LOG_WARNING}, {" ERROR", &hLogErr, LOG_FILE, TRUE, LOG_ERR} }; /***************************************** * Function Prototypes * *****************************************/ static int InitDataStructs(void); static BOOL InitLogging(void); static pLoggingFacilityInfo GetLogInfoPtr(LogHandle hLog); static BOOL GetFreeLogInfo(pLogHandle Dest); static void CloseAllLoggingFacilities(void); static BOOL SyslogOpen(pLoggingFacilityInfo pInfo); /************************************************************* * GetCurrentTimeString - * * Writes the current date & time into *buf * *************************************************************/ BOOL GetCurrentTimeString(char *buf) { /* Note: The specs for ctime_r and asctime_r say that Buffer needs * to be 26 characters long. Not sure if that includes a triling * NULL - SCM */ time_t t; struct tm tm; ASSERT(buf != NULL); time(&t); localtime_r(&t, &tm); asctime_r(&tm, buf); /* asctime_r puts a \n at the end, so we'll remove that */ buf[strlen(buf) - 1] = '\0'; return TRUE; } /*********************************************************************** * InitDataStructs - * * Called durining initalization to set up the LogInfo array * ***********************************************************************/ static int InitDataStructs(void) { unsigned int i; for (i = 0; i < (sizeof(LogInfo) / sizeof(LogInfo[0])); i++) { LogInfo[i].Initialized = FALSE; LogInfo[i].Descrip[0] = '\0'; LogInfo[i].LogOption = DefaultLogOption; } Initialized = TRUE; return TRUE; } /********************************************************************** * GetFreeLogInfo - * * Return the handle for the next available Log Facility structure * * After calling this function, the facility will be marked as in use * ***********************************************************************/ static BOOL GetFreeLogInfo(pLogHandle Dest) { u_int32 i; if (!Initialized) { InitDataStructs(); } for (i = 0; i < (sizeof(LogInfo) / sizeof(LogInfo[0])); i++) { if (LogInfo[i].Initialized == FALSE) { /* Set this here so that we don't return the same identifier twice in the case where GetFreeLogInfo() is called twice in a row */ LogInfo[i].Initialized = TRUE; *Dest = i; return TRUE; } } #ifdef DEV fprintf(stderr, "No available thread logging structs.\n"); #endif return FALSE; } /********************************************************************** * GetLogInfoPtr - * * Given a handle, return a pointer to the appropriate LoggingFacilityInfo * structure * ***********************************************************************/ static pLoggingFacilityInfo GetLogInfoPtr(LogHandle hLog) { if (hLog >= (sizeof(LogInfo) / sizeof(LogInfo[0]))) { #ifdef DEV fprintf(stderr, "Illegal LogHandle value: %#X\n", hLog); #endif return NULL; } if (LogInfo[hLog].Initialized != TRUE) { #ifdef DEV fprintf(stderr, "GetLogInfoPtr() called for a non-initialized handle\n"); #endif return NULL; } return &(LogInfo[hLog]); } /*********************************************************************** * NewLoggingFacility - * * Given an ID ( char string which will appear in the messages ), * open a logging facility and return a handle to it in * pLoggingStuff->phLog * ***********************************************************************/ BOOL NewLoggingFacility(char *ID, pLoggingFacility pStuff) { pLoggingFacilityInfo pInfo = NULL; LogHandle hLog; pLogHandle Result; /* See if there's room in the array. * This'd be nice if it were dynamically allocated */ if (!GetFreeLogInfo(&hLog)) { return FALSE; } /* Get a pointer to the syslog_data structure */ if ((pInfo = GetLogInfoPtr(hLog)) == NULL) { return FALSE; } Result = pStuff->phLog; /* Set this before the filename is checked because we may want to use the descrip and/or filename in the logs */ pInfo->UseSyslog = pStuff->UseSyslog; pInfo->LogOption = DefaultLogOption; pInfo->pid = 0; pInfo->LogLevel = pStuff->LogLevel; /* truncate description to fit buffer */ snprintf(pInfo->Descrip, sizeof(pInfo->Descrip), "%s %s", pStuff->Label, ID); /* Some sanity checking on filename... */ if ((pStuff->Filename != NULL) && (strlen(pStuff->Filename) > 0)) { FILE *fd; #if TRUNCATE_LOGS_ON_START /* * Truncating files on the start will present problems if the user * creates their own logging facilities after the program's been * running for a while. But the non-syslog logging is intended for * debug purposes only, anyway. */ char FileMode[] = "w"; #else char FileMode[] = "a"; #endif /* TRUNCATE_LOGS_ON_START */ if ((fd = fopen((pStuff->Filename), FileMode)) == NULL) { #ifdef DEV fprintf(stderr, "%s could not be opened\n", pStuff->Filename); #endif pInfo->Filename = NULL; } else { /* Tag the file */ char buf[100]; GetCurrentTimeString(&(buf[0])); #ifdef DEV #if TRUNCATE_LOGS_ON_START /* buf contains the date stamp */ fprintf(fd, "********* %s %s truncated *********\n", buf, pStuff->Filename); #else fprintf(fd, "********* %s \"%s\" logging to %s *********\n", buf, pInfo->Descrip, pStuff->Filename); #endif /* TRUNCATE_LOGS_ON_START */ #endif fflush(fd); fclose(fd); pInfo->Filename = pStuff->Filename; } } else { pInfo->Filename = NULL; } if (pInfo->UseSyslog) { /* open the logging facility */ if (!SyslogOpen(pInfo)) { return FALSE; } } /* Redundant; Initialized is set to 1 in GetFreeLogInfo */ pInfo->Initialized = TRUE; *Result = hLog; return TRUE; } /*********************************************************************** * CloseLoggingFacility - * * Closes the logging facility whose handle is hLog. * Sets up the data structure for reuse later if desired * ***********************************************************************/ BOOL CloseLoggingFacility(LogHandle hLog) { pLoggingFacilityInfo pInfo = NULL; if ((pInfo = GetLogInfoPtr(hLog)) == NULL) { return FALSE; } pInfo->Descrip[0] = '\0'; pInfo->LogOption = 0; pInfo->Filename = NULL; pInfo->pid = 0; if (pInfo->UseSyslog) { closelog(); } pInfo->Initialized = FALSE; return TRUE; } /***************************************** * CloseAllLoggingFacilities - * * Closes down all the logging stuff we've set up *****************************************/ static void CloseAllLoggingFacilities(void) { u_int32 i = 0; for (i = 0; i < (sizeof(LogInfo) / sizeof(LogInfo[0])); i++) { /* Makes assumption that these handles all are sequential. Bad Style */ if (LogInfo[i].Initialized) { CloseLoggingFacility(i); } } return; } /*********************************************************************** * PKCS_Log - * * The primitive logging function which logs a message on hLog * ***********************************************************************/ BOOL PKCS_Log(pLogHandle phLog, char *fmt, va_list ap) { char buf[PATH_MAX]; pLoggingFacilityInfo pInfo; int snres; if (fmt == NULL) { return FALSE; } if ((pInfo = GetLogInfoPtr(*phLog)) == NULL) { return FALSE; } if ((pInfo->pid != getpid()) && (pInfo->UseSyslog)) { /* Looks like our PID changed since the last call. We have to re-open */ if (!SyslogOpen(pInfo)) { return FALSE; } } snres = vsnprintf(buf, PATH_MAX, fmt, ap); if (snres < 0 || snres >= PATH_MAX) { /* Error reporting functions should be rather robust, * don't you think? */ /* vsprintf reporting an error */ //fprintf(stderr, "PKCS_ErrLog - //vsprintf error for format string %s\n", Format); return FALSE; } /* Get rid of trailing newlines. */ while (strlen(buf) && (buf[strlen(buf) - 1] == '\n')) { buf[strlen(buf) - 1] = '\0'; } // Development work only. No loging to anything other than syslog for // production level code /* * 1/17/00 SCM - If we're not a daemon, we need to print something to * stderr for warnings and errors regardless of development/production. * This is for errors that occur during startup. I'll agree that we don't * need to write to a log file in production mode, however. */ /* * Production mode: Write to stderr if we're not a daemon, and the priority * of the message is at least LOG_WARNING Development mode: Write to stderr * if we're not a daemon */ if (!IsDaemon()) { BOOL WriteNow; #ifdef DEV WriteNow = TRUE; #else WriteNow = (pInfo->LogLevel <= LOG_WARNING); #endif /* DEV */ if (WriteNow) { fprintf(stderr, "%s[%d.%d]: %s\n", pInfo->Descrip, getpid(), (int) pthread_self(), buf); } } /* Don't log to a separate log file in production mode */ #ifdef DEV if (pInfo->Filename != NULL) { FILE *fd; if ((fd = fopen(pInfo->Filename, "a+")) == NULL) { fprintf(stderr, "PKCS_Log: fopen failed for %s\n", pInfo->Filename); } else { char timebuf[32]; /* Specs say 26-character array */ GetCurrentTimeString(timebuf); /* Date/Time stamp, descrip, Error message */ fprintf(fd, "%s %s[%d.%d]: ", timebuf, pInfo->Descrip, getpid(), pthread_self()); fprintf(fd, "%s\n", buf); fflush(fd); fclose(fd); } } /* end if pInfo->Filename */ #endif /* DEV */ /* Always log to syslog, if we're using it */ if (pInfo->UseSyslog) { syslog(pInfo->LogLevel, "%s", buf); } return TRUE; } /**************************************************************************** * * Would like to have a generic function to which I pass the hLog where I'd * like to do the logging and have a #defined macro which passes it along... * * But the preprocessor and variable # args don't work & play well together * ****************************************************************************/ /***************************************** * DbgLog - * * Log messages using the debug facility *****************************************/ void DbgLog(u_int32 DebugLevel, char *Format, ...) { va_list ap; if (DebugLevel > SysDebugLevel) { return; } if (!LoggingInitialized) { InitLogging(); } va_start(ap, Format); PKCS_Log(&hLogDebug, Format, ap); va_end(ap); return; } /***************************************** * ErrLog - * * Log Messges using the error facility *****************************************/ void ErrLog(char *Format, ...) { va_list ap; if (!LoggingInitialized) { InitLogging(); } va_start(ap, Format); PKCS_Log(&hLogErr, Format, ap); va_end(ap); return; } /***************************************** * LogLog - * * Log messages using the log facility *****************************************/ void LogLog(char *Format, ...) { va_list ap; if (!LoggingInitialized) { InitLogging(); } va_start(ap, Format); PKCS_Log(&hLogLog, Format, ap); va_end(ap); return; } /***************************************** * WarnLog - * * Log messages using the warning facility *****************************************/ void WarnLog(char *Format, ...) { va_list ap; if (!LoggingInitialized) { InitLogging(); } va_start(ap, Format); PKCS_Log(&hLogWarn, Format, ap); va_end(ap); return; } /***************************************** * TraceLog - * * Log messages using the trace facility *****************************************/ void TraceLog(char *Format, ...) { va_list ap; if (!LoggingInitialized) { InitLogging(); } va_start(ap, Format); PKCS_Log(&hLogTrace, Format, ap); va_end(ap); return; } /***************************************** * InfoLog - * * Log messages using the info facility *****************************************/ void InfoLog(char *Format, ...) { va_list ap; if (!LoggingInitialized) { InitLogging(); } va_start(ap, Format); PKCS_Log(&hLogInfo, Format, ap); va_end(ap); return; } /*********************************************************************** * InitLogging - * * Sets up the various logging facilities. Must be called before * any of the logging functions can be used. ***********************************************************************/ static BOOL InitLogging(void) { unsigned int i; char *s = ProgramName; /* if ProgramName is NULL, we'll just print the level... */ if (ProgramName == NULL) { s = ""; } /* Set up logging for all the facilities in SystemLogFacilities[] */ for (i = 0; i < (sizeof(SystemLogFacilities) / (sizeof(SystemLogFacilities[0]))); i++) { if (!NewLoggingFacility(s, &(SystemLogFacilities[i]))) { #ifdef DEV fprintf(stderr, "InitLogging: NewLoggingFacility failed: %s\n", s); #endif return FALSE; } } /* end for i */ atexit(CloseAllLoggingFacilities); LoggingInitialized = TRUE; return TRUE; } /************************************************************* * SetDebugLevel - * * * Sets the level at which debug messages get logged to Val. * Returns the old value *************************************************************/ u_int32 SetDebugLevel(u_int32 Val) { u_int32 OldVal = SysDebugLevel; SysDebugLevel = Val; return OldVal; } /************************************************************* * GetDebugLevel * * Returns the level at which the program will log debug messages * *************************************************************/ u_int32 GetDebugLevel(void) { return SysDebugLevel; } #if 0 int main(int argc, char *argv[], char *envp[]) { ErrLog("This is an error test, attempt 1"); DbgLog(DEBUG_LEVEL0, "This is a DEBUG test level 0, attempt 1"); DbgLog(DEBUG_LEVEL1, "This is a DEBUG test level 1, attempt 1"); SetDebugLevel(DEBUG_NONE); DbgLog(DEBUG_LEVEL1, "This is a DEBUG test level 1, attempt 2"); DbgLog(DEBUG_LEVEL0, "This is a DEBUG test level 0, attempt 2"); ErrLog("This is an error test, attempt 2"); return 0; } #endif /* 0 */ static BOOL SyslogOpen(pLoggingFacilityInfo pInfo) { ASSERT(pInfo != NULL); if (!(pInfo->UseSyslog)) { /* it's not really an error to call SyslogOpen for a facility * that doesn't use it */ return TRUE; } if (pInfo->pid != 0) { /* We've been initialized before, so close the previous instance */ closelog(); } /* Default to log all messages. */ setlogmask(LOG_UPTO(LOG_DEBUG)); /* Mark this as having been set by this process */ pInfo->pid = getpid(); return TRUE; }