summaryrefslogtreecommitdiffstats
path: root/runtime/debug.c
diff options
context:
space:
mode:
Diffstat (limited to '')
-rw-r--r--runtime/debug.c478
1 files changed, 478 insertions, 0 deletions
diff --git a/runtime/debug.c b/runtime/debug.c
new file mode 100644
index 0000000..6e6c9fd
--- /dev/null
+++ b/runtime/debug.c
@@ -0,0 +1,478 @@
+/* debug.c
+ *
+ * This file proides debug support.
+ *
+ * File begun on 2008-01-22 by RGerhards
+ *
+ * Some functions are controlled by environment variables:
+ *
+ * RSYSLOG_DEBUGLOG if set, a debug log file is written to that location
+ * RSYSLOG_DEBUG specific debug options
+ *
+ * For details, visit doc/debug.html
+ *
+ * Copyright 2008-2018 Rainer Gerhards and Adiscon GmbH.
+ *
+ * This file is part of the rsyslog runtime library.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ * -or-
+ * see COPYING.ASL20 in the source distribution
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+#include "config.h" /* autotools! */
+#include <stdio.h>
+#include <stdlib.h>
+#include <stdarg.h>
+#include <string.h>
+#include <signal.h>
+#include <errno.h>
+#include <pthread.h>
+#include <ctype.h>
+#include <assert.h>
+#include <unistd.h>
+#include <fcntl.h>
+#include <sys/stat.h>
+#ifdef HAVE_SYS_SYSCALL_H
+# include <sys/syscall.h>
+#endif
+#if _POSIX_TIMERS <= 0
+#include <sys/time.h>
+#endif
+
+#include "rsyslog.h"
+#include "debug.h"
+#include "cfsysline.h"
+#include "obj.h"
+
+
+/* static data (some time to be replaced) */
+DEFobjCurrIf(obj)
+int Debug = DEBUG_OFF; /* debug flag - read-only after startup */
+int debugging_on = 0; /* read-only, except on sig USR1 */
+int dbgTimeoutToStderr = 0;
+static int bPrintTime = 1; /* print a timestamp together with debug message */
+static int bOutputTidToStderr = 0;/* output TID to stderr on thread creation */
+char *pszAltDbgFileName = NULL; /* if set, debug output is *also* sent to here */
+int altdbg = -1; /* and the handle for alternate debug output */
+int stddbg = 1; /* the handle for regular debug output, set to stdout if not forking, -1 otherwise */
+static uint64_t dummy_errcount = 0; /* just to avoid some static analyzer complaints */
+static pthread_key_t keyThrdName;
+
+
+/* output the current thread ID to "relevant" places
+ * (what "relevant" means is determinded by various ways)
+ */
+void
+dbgOutputTID(char* name __attribute__((unused)))
+{
+# if defined(HAVE_SYSCALL) && defined(HAVE_SYS_gettid)
+ if(bOutputTidToStderr)
+ fprintf(stderr, "thread tid %u, name '%s'\n",
+ (unsigned)syscall(SYS_gettid), name);
+ DBGPRINTF("thread created, tid %u, name '%s'\n",
+ (unsigned)syscall(SYS_gettid), name);
+# endif
+}
+
+
+/* build a string with the thread name. If none is set, the thread ID is
+ * used instead. Caller must provide buffer space.
+ */
+static void ATTR_NONNULL()
+dbgGetThrdName(char *const pszBuf, const size_t lenBuf, const pthread_t thrdID)
+{
+ assert(pszBuf != NULL);
+
+ const char *const thrdName = pthread_getspecific(keyThrdName);
+ if(thrdName == NULL) {
+ snprintf(pszBuf, lenBuf, "%lx", (long) thrdID);
+ } else {
+ snprintf(pszBuf, lenBuf, "%-15s", thrdName);
+ }
+}
+
+
+/* set a name for the current thread */
+void ATTR_NONNULL()
+dbgSetThrdName(const uchar *const pszName)
+{
+ (void) pthread_setspecific(keyThrdName, strdup((char*) pszName));
+}
+
+
+/* destructor for thread name (called by pthreads!) */
+static void dbgThrdNameDestruct(void *arg)
+{
+ free(arg);
+}
+
+
+/* write the debug message. This is a helper to dbgprintf and dbgoprint which
+ * contains common code. added 2008-09-26 rgerhards
+ * Note: We need to split the function due to the bad nature of POSIX
+ * cancel cleanup handlers.
+ */
+static void DBGL_UNUSED
+dbgprint(obj_t *pObj, char *pszMsg, const char *pszFileName, const size_t lenMsg)
+{
+ uchar *pszObjName = NULL;
+ static pthread_t ptLastThrdID = 0;
+ static int bWasNL = 0;
+ char pszThrdName[64]; /* 64 is to be on the safe side, anything over 20 is bad... */
+ char pszWriteBuf[32*1024];
+ size_t lenCopy;
+ size_t offsWriteBuf = 0;
+ size_t lenWriteBuf;
+ struct timespec t;
+# if _POSIX_TIMERS <= 0
+ struct timeval tv;
+# endif
+
+ if(pObj != NULL) {
+ pszObjName = obj.GetName(pObj);
+ }
+
+ /* The bWasNL handler does not really work. It works if no thread
+ * switching occurs during non-NL messages. Else, things are messed
+ * up. Anyhow, it works well enough to provide useful help during
+ * getting this up and running. It is questionable if the extra effort
+ * is worth fixing it, giving the limited appliability. -- rgerhards, 2005-10-25
+ * I have decided that it is not worth fixing it - especially as it works
+ * pretty well. -- rgerhards, 2007-06-15
+ */
+ if(ptLastThrdID != pthread_self()) {
+ if(!bWasNL) {
+ pszWriteBuf[0] = '\n';
+ offsWriteBuf = 1;
+ bWasNL = 1;
+ }
+ ptLastThrdID = pthread_self();
+ }
+
+ dbgGetThrdName(pszThrdName, sizeof(pszThrdName), ptLastThrdID);
+
+ if(bWasNL) {
+ if(bPrintTime) {
+# if _POSIX_TIMERS > 0
+ /* this is the "regular" code */
+ clock_gettime(CLOCK_REALTIME, &t);
+# else
+ gettimeofday(&tv, NULL);
+ t.tv_sec = tv.tv_sec;
+ t.tv_nsec = tv.tv_usec * 1000;
+# endif
+ lenWriteBuf = snprintf(pszWriteBuf+offsWriteBuf, sizeof(pszWriteBuf) - offsWriteBuf,
+ "%4.4ld.%9.9ld:", (long) (t.tv_sec % 10000), t.tv_nsec);
+ offsWriteBuf += lenWriteBuf;
+ }
+
+ lenWriteBuf = snprintf(pszWriteBuf + offsWriteBuf, sizeof(pszWriteBuf) - offsWriteBuf,
+ "%s: ", pszThrdName);
+ offsWriteBuf += lenWriteBuf;
+ /* print object name header if we have an object */
+ if(pszObjName != NULL) {
+ lenWriteBuf = snprintf(pszWriteBuf + offsWriteBuf, sizeof(pszWriteBuf) - offsWriteBuf,
+ "%s: ", pszObjName);
+ offsWriteBuf += lenWriteBuf;
+ }
+ lenWriteBuf = snprintf(pszWriteBuf + offsWriteBuf, sizeof(pszWriteBuf) - offsWriteBuf,
+ "%s: ", pszFileName);
+ offsWriteBuf += lenWriteBuf;
+ }
+ if(lenMsg > sizeof(pszWriteBuf) - offsWriteBuf)
+ lenCopy = sizeof(pszWriteBuf) - offsWriteBuf;
+ else
+ lenCopy = lenMsg;
+ memcpy(pszWriteBuf + offsWriteBuf, pszMsg, lenCopy);
+ offsWriteBuf += lenCopy;
+ /* the write is included in an "if" just to silence compiler
+ * warnings. Here, we really don't care if the write fails, we
+ * have no good response to that in any case... -- rgerhards, 2012-11-28
+ */
+ if(stddbg != -1) {
+ if(write(stddbg, pszWriteBuf, offsWriteBuf)) {
+ ++dummy_errcount;
+ }
+ }
+ if(altdbg != -1) {
+ if(write(altdbg, pszWriteBuf, offsWriteBuf)) {
+ ++dummy_errcount;
+ }
+ }
+
+ bWasNL = (pszMsg[lenMsg - 1] == '\n') ? 1 : 0;
+}
+
+
+static int DBGL_UNUSED
+checkDbgFile(const char *srcname)
+{
+ if(glblDbgFilesNum == 0) {
+ return 1;
+ }
+ if(glblDbgWhitelist) {
+ if(bsearch(srcname, glblDbgFiles, glblDbgFilesNum, sizeof(char*), bs_arrcmp_glblDbgFiles) == NULL) {
+ return 0;
+ } else {
+ return 1;
+ }
+ } else {
+ if(bsearch(srcname, glblDbgFiles, glblDbgFilesNum, sizeof(char*), bs_arrcmp_glblDbgFiles) != NULL) {
+ return 0;
+ } else {
+ return 1;
+ }
+ }
+}
+/* print some debug output when an object is given
+ * This is mostly a copy of dbgprintf, but I do not know how to combine it
+ * into a single function as we have variable arguments and I don't know how to call
+ * from one vararg function into another. I don't dig in this, it is OK for the
+ * time being. -- rgerhards, 2008-01-29
+ */
+#ifndef DEBUGLESS
+void
+r_dbgoprint( const char *srcname, obj_t *pObj, const char *fmt, ...)
+{
+ va_list ap;
+ char pszWriteBuf[32*1024];
+ size_t lenWriteBuf;
+
+ if(!(Debug && debugging_on))
+ return;
+
+ if(!checkDbgFile(srcname)) {
+ return;
+ }
+
+ va_start(ap, fmt);
+ lenWriteBuf = vsnprintf(pszWriteBuf, sizeof(pszWriteBuf), fmt, ap);
+ va_end(ap);
+ if(lenWriteBuf >= sizeof(pszWriteBuf)) {
+ /* prevent buffer overrruns and garbagge display */
+ pszWriteBuf[sizeof(pszWriteBuf) - 5] = '.';
+ pszWriteBuf[sizeof(pszWriteBuf) - 4] = '.';
+ pszWriteBuf[sizeof(pszWriteBuf) - 3] = '.';
+ pszWriteBuf[sizeof(pszWriteBuf) - 2] = '\n';
+ pszWriteBuf[sizeof(pszWriteBuf) - 1] = '\0';
+ lenWriteBuf = sizeof(pszWriteBuf);
+ }
+ dbgprint(pObj, pszWriteBuf, srcname, lenWriteBuf);
+}
+#endif
+
+/* print some debug output when no object is given
+ * WARNING: duplicate code, see dbgoprint above!
+ */
+#ifndef DEBUGLESS
+void
+r_dbgprintf(const char *srcname, const char *fmt, ...)
+{
+ va_list ap;
+ char pszWriteBuf[32*1024];
+ size_t lenWriteBuf;
+
+ if(!(Debug && debugging_on)) {
+ return;
+ }
+
+ if(!checkDbgFile(srcname)) {
+ return;
+ }
+
+ va_start(ap, fmt);
+ lenWriteBuf = vsnprintf(pszWriteBuf, sizeof(pszWriteBuf), fmt, ap);
+ va_end(ap);
+ if(lenWriteBuf >= sizeof(pszWriteBuf)) {
+ /* prevent buffer overrruns and garbagge display */
+ pszWriteBuf[sizeof(pszWriteBuf) - 5] = '.';
+ pszWriteBuf[sizeof(pszWriteBuf) - 4] = '.';
+ pszWriteBuf[sizeof(pszWriteBuf) - 3] = '.';
+ pszWriteBuf[sizeof(pszWriteBuf) - 2] = '\n';
+ pszWriteBuf[sizeof(pszWriteBuf) - 1] = '\0';
+ lenWriteBuf = sizeof(pszWriteBuf);
+ }
+ dbgprint(NULL, pszWriteBuf, srcname, lenWriteBuf);
+}
+#endif
+
+/* support system to set debug options at runtime */
+
+
+/* parse a param/value pair from the current location of the
+ * option string. Returns 1 if an option was found, 0
+ * otherwise. 0 means there are NO MORE options to be
+ * processed. -- rgerhards, 2008-02-28
+ */
+static int ATTR_NONNULL()
+dbgGetRTOptNamVal(const uchar **const ppszOpt, uchar **const ppOptName)
+{
+ assert(ppszOpt != NULL);
+ assert(*ppszOpt != NULL);
+ int bRet = 0;
+ const uchar *p = *ppszOpt;
+ size_t i;
+ static uchar optname[128] = "";
+
+ /* skip whitespace */
+ while(*p && isspace(*p))
+ ++p;
+
+ /* name: up until whitespace */
+ i = 0;
+ while(i < (sizeof(optname) - 1) && *p && !isspace(*p)) {
+ optname[i++] = *p++;
+ }
+
+ if(i > 0) {
+ bRet = 1;
+ optname[i] = '\0';
+ }
+
+ /* done */
+ *ppszOpt = p;
+ *ppOptName = optname;
+ return bRet;
+}
+
+
+/* report fd used for debug log. This is needed in case of
+ * auto-backgrounding, where the debug log shall not be closed.
+ */
+int
+dbgGetDbglogFd(void)
+{
+ return altdbg;
+}
+
+/* read in the runtime options
+ * rgerhards, 2008-02-28
+ */
+static void
+dbgGetRuntimeOptions(void)
+{
+ const uchar *pszOpts;
+ uchar *optname;
+
+ /* set some defaults */
+ if((pszOpts = (uchar*) getenv("RSYSLOG_DEBUG")) != NULL) {
+ /* we have options set, so let's process them */
+ while(dbgGetRTOptNamVal(&pszOpts, &optname)) {
+ if(!strcasecmp((char*)optname, "help")) {
+ fprintf(stderr,
+ "rsyslogd " VERSION " runtime debug support - help requested, "
+ "rsyslog terminates\n\nenvironment variables:\n"
+ "additional logfile: export RSYSLOG_DEBUGFILE=\"/path/to/file\"\n"
+ "to set: export RSYSLOG_DEBUG=\"cmd cmd cmd\"\n\n"
+ "Commands are (all case-insensitive):\n"
+ "help (this list, terminates rsyslogd)\n"
+ "NoLogTimestamp\n"
+ "Nostdout\n"
+ "OutputTidToStderr\n"
+ "DebugOnDemand - enables debugging on USR1, but does not turn on output\n"
+ "\nSee debug.html in your doc set or https://www.rsyslog.com for details\n");
+ exit(1);
+ } else if(!strcasecmp((char*)optname, "debug")) {
+ /* this is earlier in the process than the -d option, as such it
+ * allows us to spit out debug messages from the very beginning.
+ */
+ Debug = DEBUG_FULL;
+ debugging_on = 1;
+ } else if(!strcasecmp((char*)optname, "debugondemand")) {
+ /* Enables debugging, but turns off debug output */
+ Debug = DEBUG_ONDEMAND;
+ debugging_on = 1;
+ dbgprintf("Note: debug on demand turned on via configuration file, "
+ "use USR1 signal to activate.\n");
+ debugging_on = 0;
+ } else if(!strcasecmp((char*)optname, "nologtimestamp")) {
+ bPrintTime = 0;
+ } else if(!strcasecmp((char*)optname, "nostdout")) {
+ stddbg = -1;
+ } else if(!strcasecmp((char*)optname, "outputtidtostderr")) {
+ bOutputTidToStderr = 1;
+ } else {
+ fprintf(stderr, "rsyslogd " VERSION " error: invalid debug option '%s' "
+ "- ignored\n", optname);
+ }
+ }
+ }
+}
+
+
+void
+dbgSetDebugLevel(int level)
+{
+ Debug = level;
+ debugging_on = (level == DEBUG_FULL) ? 1 : 0;
+}
+
+void
+dbgSetDebugFile(uchar *fn)
+{
+ if(altdbg != -1) {
+ dbgprintf("switching to debug file %s\n", fn);
+ close(altdbg);
+ }
+ if((altdbg = open((char*)fn, O_WRONLY|O_CREAT|O_TRUNC|O_NOCTTY|O_CLOEXEC, S_IRUSR|S_IWUSR)) == -1) {
+ fprintf(stderr, "alternate debug file could not be opened, ignoring. Error: %s\n", strerror(errno));
+ }
+}
+
+/* end support system to set debug options at runtime */
+
+rsRetVal dbgClassInit(void)
+{
+ rsRetVal iRet; /* do not use DEFiRet, as this makes calls into the debug system! */
+
+
+ (void) pthread_key_create(&keyThrdName, dbgThrdNameDestruct);
+
+ /* while we try not to use any of the real rsyslog code (to avoid infinite loops), we
+ * need to have the ability to query object names. Thus, we need to obtain a pointer to
+ * the object interface. -- rgerhards, 2008-02-29
+ */
+ CHKiRet(objGetObjInterface(&obj)); /* this provides the root pointer for all other queries */
+
+ const char *dbgto2stderr;
+ dbgto2stderr = getenv("RSYSLOG_DEBUG_TIMEOUTS_TO_STDERR");
+ dbgTimeoutToStderr = (dbgto2stderr != NULL && !strcmp(dbgto2stderr, "on")) ? 1 : 0;
+ if(dbgTimeoutToStderr) {
+ fprintf(stderr, "rsyslogd: NOTE: RSYSLOG_DEBUG_TIMEOUTS_TO_STDERR activated\n");
+ }
+ dbgGetRuntimeOptions(); /* init debug system from environment */
+ pszAltDbgFileName = getenv("RSYSLOG_DEBUGLOG");
+
+ if(pszAltDbgFileName != NULL) {
+ /* we have a secondary file, so let's open it) */
+ if((altdbg = open(pszAltDbgFileName, O_WRONLY|O_CREAT|O_TRUNC|O_NOCTTY|O_CLOEXEC, S_IRUSR|S_IWUSR))
+ == -1) {
+ fprintf(stderr, "alternate debug file could not be opened, ignoring. Error: %s\n",
+ strerror(errno));
+ }
+ }
+
+ dbgSetThrdName((uchar*)"main thread");
+
+finalize_it:
+ return(iRet);
+}
+
+
+rsRetVal dbgClassExit(void)
+{
+ pthread_key_delete(keyThrdName);
+ if(altdbg != -1)
+ close(altdbg);
+ return RS_RET_OK;
+}