diff --git a/dix/dixfonts.c b/dix/dixfonts.c index dd617d99c..e67ad0f8d 100644 --- a/dix/dixfonts.c +++ b/dix/dixfonts.c @@ -2026,18 +2026,12 @@ static uint32_t wrap_time_in_millis(void) return GetTimeInMillis(); } -static void verrorf(const char *f, va_list args) _X_ATTRIBUTE_PRINTF(1, 0); -static void verrorf(const char *f, va_list args) -{ - LogVMessageVerb(X_NONE, -1, f, args); -} - static const xfont2_client_funcs_rec xfont2_client_funcs = { .version = XFONT2_CLIENT_FUNCS_VERSION, .client_auth_generation = _client_auth_generation, .client_signal = ClientSignal, .delete_font_client_id = delete_font_client_id, - .verrorf = verrorf, + .verrorf = VErrorF, .find_old_font = find_old_font, .get_client_resolutions = get_client_resolutions, .get_default_point_size = get_default_point_size, diff --git a/dix/getevents.c b/dix/getevents.c index 5242fd270..4cdd2b711 100644 --- a/dix/getevents.c +++ b/dix/getevents.c @@ -1964,8 +1964,8 @@ GetTouchEvents(InternalEvent *events, DeviceIntPtr dev, uint32_t ddx_touchid, ti = TouchFindByDDXID(dev, ddx_touchid, (type == XI_TouchBegin)); if (!ti) { - ErrorF("[dix] %s: unable to %s touch point %u\n", dev->name, - type == XI_TouchBegin ? "begin" : "find", ddx_touchid); + ErrorFSigSafe("[dix] %s: unable to %s touch point %u\n", dev->name, + type == XI_TouchBegin ? "begin" : "find", ddx_touchid); return 0; } client_id = ti->client_id; @@ -1998,14 +1998,16 @@ GetTouchEvents(InternalEvent *events, DeviceIntPtr dev, uint32_t ddx_touchid, if (!mask_in || !valuator_mask_isset(mask_in, 0) || !valuator_mask_isset(mask_in, 1)) { - ErrorF("%s: Attempted to start touch without x/y (driver bug)\n", dev->name); + ErrorFSigSafe("%s: Attempted to start touch without x/y " + "(driver bug)\n", dev->name); return 0; } break; case XI_TouchUpdate: event->type = ET_TouchUpdate; if (!mask_in || valuator_mask_num_valuators(mask_in) <= 0) { - ErrorF("%s: TouchUpdate with no valuators? Driver bug\n", dev->name); + ErrorFSigSafe("%s: TouchUpdate with no valuators? Driver bug\n", + dev->name); } break; case XI_TouchEnd: diff --git a/dix/ptrveloc.c b/dix/ptrveloc.c index 63fe07b10..192c0f5bb 100644 --- a/dix/ptrveloc.c +++ b/dix/ptrveloc.c @@ -78,7 +78,7 @@ DeletePredictableAccelerationProperties(DeviceIntPtr, /*#define PTRACCEL_DEBUGGING*/ #ifdef PTRACCEL_DEBUGGING -#define DebugAccelF(...) ErrorF("dix/ptraccel: " __VA_ARGS__) +#define DebugAccelF(...) ErrorFSigSafe("dix/ptraccel: " __VA_ARGS__) #else #define DebugAccelF(...) /* */ #endif diff --git a/glx/glxdri2.c b/glx/glxdri2.c index 4c5bc8446..c4e02b7b7 100644 --- a/glx/glxdri2.c +++ b/glx/glxdri2.c @@ -805,7 +805,7 @@ glxDRILeaveVT(ScrnInfoPtr scrn) __GLXDRIscreen *screen = (__GLXDRIscreen *) glxGetScreen(xf86ScrnToScreen(scrn)); - LogMessageVerb(X_INFO, -1, "AIGLX: Suspending AIGLX clients for VT switch\n"); + LogMessageVerbSigSafe(X_INFO, -1, "AIGLX: Suspending AIGLX clients for VT switch\n"); glxSuspendClients(); diff --git a/hw/xfree86/common/xf86Init.c b/hw/xfree86/common/xf86Init.c index 0d10794bb..bcfaf8d1d 100644 --- a/hw/xfree86/common/xf86Init.c +++ b/hw/xfree86/common/xf86Init.c @@ -856,12 +856,12 @@ ddxGiveUp(enum ExitCode error) void OsVendorFatalError(const char *f, va_list args) { - ErrorF("\nPlease consult the " XVENDORNAME " support \n\t at " - __VENDORDWEBSUPPORT__ "\n for help. \n"); + ErrorFSigSafe("\nPlease consult the " XVENDORNAME " support \n\t at " + __VENDORDWEBSUPPORT__ "\n for help. \n"); if (xf86LogFile && xf86LogFileWasOpened) - ErrorF("Please also check the log file at \"%s\" for additional " - "information.\n", xf86LogFile); - ErrorF("\n"); + ErrorFSigSafe("Please also check the log file at \"%s\" for additional " + "information.\n", xf86LogFile); + ErrorFSigSafe("\n"); } void diff --git a/hw/xfree86/drivers/inputtest/xf86-input-inputtest.c b/hw/xfree86/drivers/inputtest/xf86-input-inputtest.c index 52e58f13b..294e35747 100644 --- a/hw/xfree86/drivers/inputtest/xf86-input-inputtest.c +++ b/hw/xfree86/drivers/inputtest/xf86-input-inputtest.c @@ -126,9 +126,9 @@ notify_sync_finished(ClientPtr ptr, void *closure) already shut down and the descriptor is closed. */ if (write(fd, &response, response.header.length) != response.header.length) { - LogMessageVerb(X_ERROR, 0, - "inputtest: Failed to write sync response: %s\n", - strerror(errno)); + LogMessageVerbSigSafe(X_ERROR, 0, + "inputtest: Failed to write sync response: %s\n", + strerror(errno)); } input_unlock(); return TRUE; diff --git a/hw/xfree86/int10/xf86x86emu.c b/hw/xfree86/int10/xf86x86emu.c index 5a3a5484f..1dc695d2c 100644 --- a/hw/xfree86/int10/xf86x86emu.c +++ b/hw/xfree86/int10/xf86x86emu.c @@ -85,6 +85,6 @@ printk(const char *fmt, ...) va_list argptr; va_start(argptr, fmt); - LogVMessageVerb(X_NONE, -1, fmt, argptr); + VErrorF(fmt, argptr); va_end(argptr); } diff --git a/hw/xfree86/loader/loader.c b/hw/xfree86/loader/loader.c index 5af7a54f3..4696b639d 100644 --- a/hw/xfree86/loader/loader.c +++ b/hw/xfree86/loader/loader.c @@ -141,7 +141,7 @@ LoaderSymbolFromModule(void *handle, const char *name) void LoaderUnload(const char *name, void *handle) { - LogMessageVerb(X_INFO, 1, "Unloading %s\n", name); + LogMessageVerbSigSafe(X_INFO, 1, "Unloading %s\n", name); if (handle) dlclose(handle); } diff --git a/hw/xfree86/loader/loadmod.c b/hw/xfree86/loader/loadmod.c index 9bb7aa47b..cca11028c 100644 --- a/hw/xfree86/loader/loadmod.c +++ b/hw/xfree86/loader/loadmod.c @@ -854,9 +854,9 @@ UnloadModule(void *_mod) const char *name = mod->VersionInfo->modname; if (mod->parent) - LogMessageVerb(X_INFO, 3, "UnloadSubModule: \"%s\"\n", name); + LogMessageVerbSigSafe(X_INFO, 3, "UnloadSubModule: \"%s\"\n", name); else - LogMessageVerb(X_INFO, 3, "UnloadModule: \"%s\"\n", name); + LogMessageVerbSigSafe(X_INFO, 3, "UnloadModule: \"%s\"\n", name); if (mod->TearDownData != ModuleDuplicated) { if ((mod->TearDownProc) && (mod->TearDownData)) diff --git a/hw/xfree86/parser/configProcs.h b/hw/xfree86/parser/configProcs.h index 93e3e6706..39399b7bc 100644 --- a/hw/xfree86/parser/configProcs.h +++ b/hw/xfree86/parser/configProcs.h @@ -145,4 +145,6 @@ xf86freeExtensions(XF86ConfExtensionsPtr ptr); /* Externally provided functions */ void ErrorF(const char *f, ...); +void +VErrorF(const char *f, va_list args); #endif diff --git a/hw/xfree86/parser/scan.c b/hw/xfree86/parser/scan.c index 3655eb777..bf5a8d13b 100644 --- a/hw/xfree86/parser/scan.c +++ b/hw/xfree86/parser/scan.c @@ -974,7 +974,7 @@ xf86parseError(const char *format, ...) ErrorF("Parse error on line %d of section %s in file %s\n\t", configLineNo, configSection, filename); va_start(ap, format); - LogVMessageVerb(X_NONE, -1, format, ap); + VErrorF(format, ap); va_end(ap); ErrorF("\n"); @@ -989,7 +989,7 @@ xf86validationError(const char *format, ...) ErrorF("Data incomplete in file %s\n\t", filename); va_start(ap, format); - LogVMessageVerb(X_NONE, -1, format, ap); + VErrorF(format, ap); va_end(ap); ErrorF("\n"); diff --git a/hw/xwayland/xwayland-screen.c b/hw/xwayland/xwayland-screen.c index 7c8d802d0..5bc3551e3 100644 --- a/hw/xwayland/xwayland-screen.c +++ b/hw/xwayland/xwayland-screen.c @@ -90,7 +90,7 @@ xwl_give_up(const char *f, ...) va_list args; va_start(args, f); - LogVMessageVerb(X_NONE, -1, f, args); + VErrorFSigSafe(f, args); va_end(args); CloseWellKnownConnections(); diff --git a/hw/xwin/InitOutput.c b/hw/xwin/InitOutput.c index a8a8cac24..541503552 100644 --- a/hw/xwin/InitOutput.c +++ b/hw/xwin/InitOutput.c @@ -633,6 +633,9 @@ OsVendorInit(void) winFixupPaths(); + if (!OsVendorVErrorFProc) + OsVendorVErrorFProc = OsVendorVErrorF; + if (!g_fLogInited) { /* keep this order. If LogInit fails it calls Abort which then calls * ddxGiveUp where LogInit is called again and creates an infinite diff --git a/hw/xwin/win.h b/hw/xwin/win.h index 44736a08b..49a2031d3 100644 --- a/hw/xwin/win.h +++ b/hw/xwin/win.h @@ -742,6 +742,10 @@ void * winerror.c */ +void +OsVendorVErrorF(const char *pszFormat, va_list va_args) +_X_ATTRIBUTE_PRINTF(1, 0); + void winMessageBoxF(const char *pszError, UINT uType, ...) _X_ATTRIBUTE_PRINTF(1, 3); diff --git a/hw/xwin/winerror.c b/hw/xwin/winerror.c index 401481327..bdf03f053 100644 --- a/hw/xwin/winerror.c +++ b/hw/xwin/winerror.c @@ -39,6 +39,23 @@ #include "dix/input_priv.h" +void +OsVendorVErrorF(const char *pszFormat, va_list va_args) +{ + /* make sure the clipboard and multiwindow threads do not interfere the + * main thread */ + static pthread_mutex_t s_pmPrinting = PTHREAD_MUTEX_INITIALIZER; + + /* Lock the printing mutex */ + pthread_mutex_lock(&s_pmPrinting); + + /* Print the error message to a log file, could be stderr */ + LogVMessageVerb(X_NONE, 0, pszFormat, va_args); + + /* Unlock the printing mutex */ + pthread_mutex_unlock(&s_pmPrinting); +} + /* * os/log.c:FatalError () calls our vendor ErrorF, so the message * from a FatalError will be logged. diff --git a/hw/xwin/winprocarg.c b/hw/xwin/winprocarg.c index d87c40936..4f753982f 100644 --- a/hw/xwin/winprocarg.c +++ b/hw/xwin/winprocarg.c @@ -225,6 +225,12 @@ ddxProcessArgument(int argc, char *argv[], int i) /* Initialize once */ if (!s_fBeenHere) { + /* + * This initialises our hook into VErrorF () for catching log messages + * that are generated before OsInit () is called. + */ + OsVendorVErrorFProc = OsVendorVErrorF; + s_fBeenHere = TRUE; /* Initialize only if option is not -help */ diff --git a/include/misc.h b/include/misc.h index 45e4370cc..ba179ff87 100644 --- a/include/misc.h +++ b/include/misc.h @@ -377,10 +377,10 @@ extern _X_EXPORT unsigned long serverGeneration; /* Don't use this directly, use BUG_WARN or BUG_WARN_MSG instead */ #define __BUG_WARN_MSG(cond, with_msg, ...) \ do { if (cond) { \ - ErrorF("BUG: triggered 'if (" #cond ")'\n"); \ - ErrorF("BUG: %s:%u in %s()\n", \ - __FILE__, __LINE__, __func__); \ - if (with_msg) ErrorF(__VA_ARGS__); \ + ErrorFSigSafe("BUG: triggered 'if (" #cond ")'\n"); \ + ErrorFSigSafe("BUG: %s:%u in %s()\n", \ + __FILE__, __LINE__, __func__); \ + if (with_msg) ErrorFSigSafe(__VA_ARGS__); \ xorg_backtrace(); \ } } while(0) diff --git a/include/os.h b/include/os.h index 3f2bdfbc0..3949ff5aa 100644 --- a/include/os.h +++ b/include/os.h @@ -324,6 +324,12 @@ _X_ATTRIBUTE_PRINTF(3, 4); extern _X_EXPORT void LogMessage(MessageType type, const char *format, ...) _X_ATTRIBUTE_PRINTF(2, 3); +extern _X_EXPORT void +LogMessageVerbSigSafe(MessageType type, int verb, const char *format, ...) +_X_ATTRIBUTE_PRINTF(3, 4); +extern _X_EXPORT void +LogVMessageVerbSigSafe(MessageType type, int verb, const char *format, va_list args) +_X_ATTRIBUTE_PRINTF(3, 0); extern _X_EXPORT void LogVHdrMessageVerb(MessageType type, int verb, @@ -349,10 +355,19 @@ _X_ATTRIBUTE_PRINTF(1, 2) #define DebugF(...) /* */ #endif +extern _X_EXPORT void +VErrorF(const char *f, va_list args) +_X_ATTRIBUTE_PRINTF(1, 0); extern _X_EXPORT void ErrorF(const char *f, ...) _X_ATTRIBUTE_PRINTF(1, 2); extern _X_EXPORT void +VErrorFSigSafe(const char *f, va_list args) +_X_ATTRIBUTE_PRINTF(1, 0); +extern _X_EXPORT void +ErrorFSigSafe(const char *f, ...) +_X_ATTRIBUTE_PRINTF(1, 2); +extern _X_EXPORT void LogPrintMarkers(void); extern _X_EXPORT void @@ -364,13 +379,6 @@ xorg_backtrace(void); typedef _sigset_t sigset_t; #endif -/* should not be used anymore, just for backwards compat with drivers */ -#define LogVMessageVerbSigSafe(...) LogVMessageVerb(__VA_ARGS__) -#define LogMessageVerbSigSafe(...) LogMessageVerb(__VA_ARGS__) -#define ErrorFSigSafe(...) ErrorF(__VA_ARGS__) -#define VErrorFSigSafe(...) VErrorF(__VA_ARGS__) -#define VErrorF(...) LogVMessageVerb(X_NONE, -1, __VA_ARGS__) - /* only for backwards compat with drivers that haven't kept up yet (xf86-video-intel) diff --git a/mi/mieq.c b/mi/mieq.c index 6d9e3eb87..852732b98 100644 --- a/mi/mieq.c +++ b/mi/mieq.c @@ -227,22 +227,22 @@ mieqEnqueue(DeviceIntPtr pDev, InternalEvent *e) */ miEventQueue.dropped++; if (miEventQueue.dropped == 1) { - ErrorF("[mi] EQ overflowing. Additional events will be " - "discarded until existing events are processed.\n"); + ErrorFSigSafe("[mi] EQ overflowing. Additional events will be " + "discarded until existing events are processed.\n"); xorg_backtrace(); - ErrorF("[mi] These backtraces from mieqEnqueue may point to " - "a culprit higher up the stack.\n"); - ErrorF("[mi] mieq is *NOT* the cause. It is a victim.\n"); + ErrorFSigSafe("[mi] These backtraces from mieqEnqueue may point to " + "a culprit higher up the stack.\n"); + ErrorFSigSafe("[mi] mieq is *NOT* the cause. It is a victim.\n"); } else if (miEventQueue.dropped % QUEUE_DROP_BACKTRACE_FREQUENCY == 0 && miEventQueue.dropped / QUEUE_DROP_BACKTRACE_FREQUENCY <= QUEUE_DROP_BACKTRACE_MAX) { - ErrorF("[mi] EQ overflow continuing. %zu events have been " - "dropped.\n", miEventQueue.dropped); + ErrorFSigSafe("[mi] EQ overflow continuing. %zu events have been " + "dropped.\n", miEventQueue.dropped); if (miEventQueue.dropped / QUEUE_DROP_BACKTRACE_FREQUENCY == QUEUE_DROP_BACKTRACE_MAX) { - ErrorF("[mi] No further overflow reports will be " - "reported until the clog is cleared.\n"); + ErrorFSigSafe("[mi] No further overflow reports will be " + "reported until the clog is cleared.\n"); } xorg_backtrace(); } diff --git a/os/backtrace.c b/os/backtrace.c index aaa27d29e..281747de4 100644 --- a/os/backtrace.c +++ b/os/backtrace.c @@ -82,21 +82,21 @@ print_registers(int frame, unw_cursor_t cursor) frame++; ret = unw_step(&cursor); if (ret < 0) { - ErrorF("unw_step failed: %s [%d]\n", unw_strerror(ret), ret); + ErrorFSigSafe("unw_step failed: %s [%d]\n", unw_strerror(ret), ret); return; } - ErrorF("\n"); - ErrorF("Registers at frame #%d:\n", frame); + ErrorFSigSafe("\n"); + ErrorFSigSafe("Registers at frame #%d:\n", frame); for (i = 0; i < num_regs; i++) { unw_word_t val; ret = unw_get_reg(&cursor, regs[i].regnum, &val); if (ret < 0) { - ErrorF("unw_get_reg(%s) failed: %s [%d]\n", + ErrorFSigSafe("unw_get_reg(%s) failed: %s [%d]\n", regs[i].name, unw_strerror(ret), ret); } else { - ErrorF(" %s: 0x%" PRIxPTR "\n", regs[i].name, val); + ErrorFSigSafe(" %s: 0x%" PRIxPTR "\n", regs[i].name, val); } } } @@ -117,23 +117,26 @@ xorg_backtrace(void) pip.unwind_info = NULL; ret = unw_getcontext(&context); if (ret) { - ErrorF("unw_getcontext failed: %s [%d]\n", unw_strerror(ret), ret); + ErrorFSigSafe("unw_getcontext failed: %s [%d]\n", unw_strerror(ret), + ret); return; } ret = unw_init_local(&cursor, &context); if (ret) { - ErrorF("unw_init_local failed: %s [%d]\n", unw_strerror(ret), ret); + ErrorFSigSafe("unw_init_local failed: %s [%d]\n", unw_strerror(ret), + ret); return; } - ErrorF("\n"); - ErrorF("Backtrace:\n"); + ErrorFSigSafe("\n"); + ErrorFSigSafe("Backtrace:\n"); ret = unw_step(&cursor); while (ret > 0) { ret = unw_get_proc_info(&cursor, &pip); if (ret) { - ErrorF("unw_get_proc_info failed: %s [%d]\n", unw_strerror(ret), ret); + ErrorFSigSafe("unw_get_proc_info failed: %s [%d]\n", + unw_strerror(ret), ret); break; } @@ -141,7 +144,8 @@ xorg_backtrace(void) ret = unw_get_proc_name(&cursor, procname, 256, &off); if (ret && ret != -UNW_ENOMEM) { if (ret != -UNW_EUNSPEC) - ErrorF("unw_get_proc_name failed: %s [%d]\n", unw_strerror(ret), ret); + ErrorFSigSafe("unw_get_proc_name failed: %s [%d]\n", + unw_strerror(ret), ret); procname[0] = '?'; procname[1] = 0; } @@ -159,22 +163,22 @@ xorg_backtrace(void) signal_cursor = cursor; signal_frame = i; - ErrorF("%u: \n", i++); + ErrorFSigSafe("%u: \n", i++); } else { - ErrorF("%u: %s (%s%s+0x%x) [%p]\n", i++, filename, procname, - ret == -UNW_ENOMEM ? "..." : "", (int)off, + ErrorFSigSafe("%u: %s (%s%s+0x%x) [%p]\n", i++, filename, procname, + ret == -UNW_ENOMEM ? "..." : "", (int)off, (void *)(uintptr_t)(ip)); } ret = unw_step(&cursor); if (ret < 0) - ErrorF("unw_step failed: %s [%d]\n", unw_strerror(ret), ret); + ErrorFSigSafe("unw_step failed: %s [%d]\n", unw_strerror(ret), ret); } if (signal_frame >= 0) print_registers(signal_frame, signal_cursor); - ErrorF("\n"); + ErrorFSigSafe("\n"); } #else /* HAVE_LIBUNWIND */ #ifdef HAVE_BACKTRACE @@ -193,19 +197,19 @@ xorg_backtrace(void) int size, i; Dl_info info; - ErrorF("\n"); - ErrorF("Backtrace:\n"); + ErrorFSigSafe("\n"); + ErrorFSigSafe("Backtrace:\n"); size = backtrace(array, BT_SIZE); for (i = 0; i < size; i++) { int rc = dladdr(array[i], &info); if (rc == 0) { - ErrorF("%u: ?? [%p]\n", i, array[i]); + ErrorFSigSafe("%u: ?? [%p]\n", i, array[i]); continue; } mod = (info.dli_fname && *info.dli_fname) ? info.dli_fname : "(vdso)"; if (info.dli_saddr) - ErrorF( + ErrorFSigSafe( "%u: %s (%s+0x%x) [%p]\n", i, mod, @@ -214,7 +218,7 @@ xorg_backtrace(void) (char *) info.dli_saddr), array[i]); else - ErrorF( + ErrorFSigSafe( "%u: %s (%p+0x%x) [%p]\n", i, mod, @@ -223,7 +227,7 @@ xorg_backtrace(void) (char *) info.dli_fbase), array[i]); } - ErrorF("\n"); + ErrorFSigSafe("\n"); } #else /* not glibc or glibc < 2.1 */ @@ -261,7 +265,7 @@ xorg_backtrace_frame(uintptr_t pc, int signo, void *arg) strcpy(signame, "unknown"); } - ErrorF("** Signal %u (%s)\n", signo, signame); + ErrorFSigSafe("** Signal %u (%s)\n", signo, signame); } snprintf(header, sizeof(header), "%d: 0x%lx", depth, pc); @@ -279,7 +283,8 @@ xorg_backtrace_frame(uintptr_t pc, int signo, void *arg) symname = "
"; offset = pc - (uintptr_t) dlinfo.dli_fbase; } - ErrorF("%s: %s:%s+0x%x\n", header, dlinfo.dli_fname, symname, offset); + ErrorFSigSafe("%s: %s:%s+0x%x\n", header, dlinfo.dli_fname, symname, + offset); } else { @@ -287,7 +292,7 @@ xorg_backtrace_frame(uintptr_t pc, int signo, void *arg) * probably poke elfloader here, but haven't written that code yet, * so we just print the pc. */ - ErrorF("%s\n", header); + ErrorFSigSafe("%s\n", header); } return 0; @@ -341,7 +346,7 @@ xorg_backtrace_pstack(void) if (bytesread > 0) { btline[bytesread] = 0; - ErrorF("%s", btline); + ErrorFSigSafe("%s", btline); } else if ((bytesread < 0) || ((errno != EINTR) && (errno != EAGAIN))) done = 1; @@ -361,8 +366,8 @@ void xorg_backtrace(void) { - ErrorF("\n"); - ErrorF("Backtrace:\n"); + ErrorFSigSafe("\n"); + ErrorFSigSafe("Backtrace:\n"); #ifdef HAVE_PSTACK /* First try fork/exec of pstack - otherwise fall back to walkcontext @@ -379,9 +384,9 @@ xorg_backtrace(void) walkcontext(&u, xorg_backtrace_frame, &depth); else #endif - ErrorF("Failed to get backtrace info: %s\n", strerror(errno)); + ErrorFSigSafe("Failed to get backtrace info: %s\n", strerror(errno)); } - ErrorF("\n"); + ErrorFSigSafe("\n"); } #else diff --git a/os/log.c b/os/log.c index a7ea22a17..df9589565 100644 --- a/os/log.c +++ b/os/log.c @@ -105,6 +105,8 @@ OR PERFORMANCE OF THIS SOFTWARE. #pragma clang diagnostic ignored "-Wformat-nonliteral" #endif +void (*OsVendorVErrorFProc) (const char *, va_list args) = NULL; + /* Default logging parameters. */ #define DEFAULT_LOG_VERBOSITY 0 #define DEFAULT_LOG_FILE_VERBOSITY 3 @@ -300,7 +302,7 @@ LogClose(enum ExitCode error) { if (logFile) { int msgtype = (error == EXIT_NO_ERROR) ? X_INFO : X_ERROR; - LogMessageVerb(msgtype, -1, + LogMessageVerbSigSafe(msgtype, -1, "Server terminated %s (%d). Closing log file.\n", (error == EXIT_NO_ERROR) ? "successfully" : "with error", error); @@ -549,6 +551,19 @@ vpnprintf(char *string, int size_in, const char *f, va_list args) return s_idx; } +static int +pnprintf(char *string, int size, const char *f, ...) +{ + int rc; + va_list args; + + va_start(args, f); + rc = vpnprintf(string, size, f, args); + va_end(args); + + return rc; +} + /* This function does the actual log message writes. It must be signal safe. * When attempting to call non-signal-safe functions, guard them with a check * of the inSignalContext global variable. */ @@ -651,49 +666,40 @@ LogMessageTypeVerbString(MessageType type, int verb) } } -#define LOG_MSG_BUF_SIZE 1024 - -static ssize_t prepMsgHdr(MessageType type, int verb, char *buf) -{ - const char *type_str = LogMessageTypeVerbString(type, verb); - if (!type_str) - return -1; - - size_t prefixLen = strlen_sigsafe(type_str); - if (prefixLen) { - memcpy(buf, type_str, prefixLen + 1); // rely on buffer being big enough - buf[prefixLen] = ' '; - prefixLen++; - } - buf[prefixLen] = 0; - return prefixLen; -} - -static inline void writeLog(int verb, char *buf, int len) -{ - /* Force '\n' at end of truncated line */ - if (LOG_MSG_BUF_SIZE - len == 1) - buf[len - 1] = '\n'; - - LogSWrite(verb, buf, len, (buf[len - 1] == '\n')); -} - -/* signal safe */ void LogVMessageVerb(MessageType type, int verb, const char *format, va_list args) { - char buf[LOG_MSG_BUF_SIZE]; + const char *type_str; + char buf[1024]; + const size_t size = sizeof(buf); + Bool newline; + size_t len = 0; - size_t len = prepMsgHdr(type, verb, buf); - if (len == -1) + if (inSignalContext) { + LogVMessageVerbSigSafe(type, verb, format, args); + return; + } + + type_str = LogMessageTypeVerbString(type, verb); + if (!type_str) return; - len += vpnprintf(&buf[len], sizeof(buf) - len, format, args); + /* if type_str is not "", prepend it and ' ', to message */ + if (type_str[0] != '\0') + len += Xscnprintf(&buf[len], size - len, "%s ", type_str); - writeLog(verb, buf, len); + if (size - len > 1) + len += Xvscnprintf(&buf[len], size - len, format, args); + + /* Force '\n' at end of truncated line */ + if (size - len == 1) + buf[len - 1] = '\n'; + + newline = (buf[len - 1] == '\n'); + LogSWrite(verb, buf, len, newline); } -/* Log message with verbosity level specified. -- signal safe */ +/* Log message with verbosity level specified. */ void LogMessageVerb(MessageType type, int verb, const char *format, ...) { @@ -715,23 +721,86 @@ LogMessage(MessageType type, const char *format, ...) va_end(ap); } +/* Log a message using only signal safe functions. */ +void +LogMessageVerbSigSafe(MessageType type, int verb, const char *format, ...) +{ + va_list ap; + va_start(ap, format); + LogVMessageVerbSigSafe(type, verb, format, ap); + va_end(ap); +} + +void +LogVMessageVerbSigSafe(MessageType type, int verb, const char *format, va_list args) +{ + const char *type_str; + char buf[1024]; + int len; + Bool newline; + + type_str = LogMessageTypeVerbString(type, verb); + if (!type_str) + return; + + /* if type_str is not "", prepend it and ' ', to message */ + if (type_str[0] != '\0') { + LogSWrite(verb, type_str, strlen_sigsafe(type_str), FALSE); + LogSWrite(verb, " ", 1, FALSE); + } + + len = vpnprintf(buf, sizeof(buf), format, args); + + /* Force '\n' at end of truncated line */ + if (sizeof(buf) - len == 1) + buf[len - 1] = '\n'; + + newline = (len > 0 && buf[len - 1] == '\n'); + LogSWrite(verb, buf, len, newline); +} + void LogVHdrMessageVerb(MessageType type, int verb, const char *msg_format, va_list msg_args, const char *hdr_format, va_list hdr_args) { - char buf[LOG_MSG_BUF_SIZE]; + const char *type_str; + char buf[1024]; + const size_t size = sizeof(buf); + Bool newline; + size_t len = 0; + int (*vprintf_func)(char *, int, const char* _X_RESTRICT_KYWD f, va_list args) + _X_ATTRIBUTE_PRINTF(3, 0); + int (*printf_func)(char *, int, const char* _X_RESTRICT_KYWD f, ...) + _X_ATTRIBUTE_PRINTF(3, 4); - size_t len = prepMsgHdr(type, verb, buf); - if (len == -1) + type_str = LogMessageTypeVerbString(type, verb); + if (!type_str) return; - if (hdr_format && sizeof(buf) - len > 1) - len += vpnprintf(&buf[len], sizeof(buf) - len, hdr_format, hdr_args); + if (inSignalContext) { + vprintf_func = vpnprintf; + printf_func = pnprintf; + } else { + vprintf_func = Xvscnprintf; + printf_func = Xscnprintf; + } - if (msg_format && sizeof(buf) - len > 1) - len += vpnprintf(&buf[len], sizeof(buf) - len, msg_format, msg_args); + /* if type_str is not "", prepend it and ' ', to message */ + if (type_str[0] != '\0') + len += printf_func(&buf[len], size - len, "%s ", type_str); - writeLog(verb, buf, len); + if (hdr_format && size - len > 1) + len += vprintf_func(&buf[len], size - len, hdr_format, hdr_args); + + if (msg_format && size - len > 1) + len += vprintf_func(&buf[len], size - len, msg_format, msg_args); + + /* Force '\n' at end of truncated line */ + if (size - len == 1) + buf[len - 1] = '\n'; + + newline = (buf[len - 1] == '\n'); + LogSWrite(verb, buf, len, newline); } void @@ -854,9 +923,9 @@ FatalError(const char *f, ...) static Bool beenhere = FALSE; if (beenhere) - ErrorF("\nFatalError re-entered, aborting\n"); + ErrorFSigSafe("\nFatalError re-entered, aborting\n"); else - ErrorF("\nFatal server error:\n"); + ErrorFSigSafe("\nFatal server error:\n"); va_start(args, f); @@ -873,9 +942,9 @@ FatalError(const char *f, ...) va_end(apple_args); } #endif - LogVMessageVerb(X_NONE, -1, f, args); + VErrorFSigSafe(f, args); va_end(args); - ErrorF("\n"); + ErrorFSigSafe("\n"); if (!beenhere) OsVendorFatalError(f, args2); va_end(args2); @@ -887,13 +956,38 @@ FatalError(const char *f, ...) OsAbort(); /*NOTREACHED*/} +void +VErrorF(const char *f, va_list args) +{ + if (OsVendorVErrorFProc) + OsVendorVErrorFProc(f, args); + else + LogVMessageVerb(X_NONE, -1, f, args); +} + void ErrorF(const char *f, ...) { va_list args; va_start(args, f); - LogVMessageVerb(X_NONE, -1, f, args); + VErrorF(f, args); + va_end(args); +} + +void +VErrorFSigSafe(const char *f, va_list args) +{ + LogVMessageVerbSigSafe(X_ERROR, -1, f, args); +} + +void +ErrorFSigSafe(const char *f, ...) +{ + va_list args; + + va_start(args, f); + VErrorFSigSafe(f, args); va_end(args); } diff --git a/os/osdep.h b/os/osdep.h index 3c198a712..7a1b46bf3 100644 --- a/os/osdep.h +++ b/os/osdep.h @@ -174,6 +174,10 @@ int os_move_fd(int fd); depending on whether multithreading is used */ int xthread_sigmask(int how, const sigset_t *set, sigset_t *oldest); +/* callback for DDX specific error printing, if any (may be NULL) */ +extern void (*OsVendorVErrorFProc) (const char *, va_list args) + _X_ATTRIBUTE_PRINTF(1, 0); + typedef void (*OsSigHandlerPtr) (int sig); /* install signal handler */ diff --git a/os/osinit.c b/os/osinit.c index 3e18b51b0..3a132faee 100644 --- a/os/osinit.c +++ b/os/osinit.c @@ -119,8 +119,10 @@ OsSigHandler(int signo) if (signo == SIGNAL_FOR_RTLD_ERROR) { const char *dlerr = dlerror(); - if (dlerr) - LogMessageVerb(X_ERROR, 1, "Dynamic loader error: %s\n", dlerr); + if (dlerr) { + LogMessageVerbSigSafe(X_ERROR, 1, + "Dynamic loader error: %s\n", dlerr); + } } #endif /* RTLD_DI_SETSIGNAL */ @@ -136,8 +138,8 @@ OsSigHandler(int signo) #ifdef SA_SIGINFO if (sip->si_code == SI_USER) { - ErrorF("Received signal %u sent by process %u, uid %u\n", signo, - sip->si_pid, sip->si_uid); + ErrorFSigSafe("Received signal %u sent by process %u, uid %u\n", signo, + sip->si_pid, sip->si_uid); } else { switch (signo) { @@ -145,7 +147,7 @@ OsSigHandler(int signo) case SIGBUS: case SIGILL: case SIGFPE: - ErrorF("%s at address %p\n", strsignal(signo), sip->si_addr); + ErrorFSigSafe("%s at address %p\n", strsignal(signo), sip->si_addr); } } #endif diff --git a/test/signal-logging.c b/test/signal-logging.c index 22a01631c..db8efa852 100644 --- a/test/signal-logging.c +++ b/test/signal-logging.c @@ -202,59 +202,59 @@ static void logging_format(void) } while (0) /* boring test message */ - LogMessageVerb(X_ERROR, 1, "test message\n"); + LogMessageVerbSigSafe(X_ERROR, 1, "test message\n"); read_log_msg(logmsg); assert(strcmp(logmsg, "(EE) test message\n") == 0); /* long buf is truncated to "....en\n" */ - LogMessageVerb(X_ERROR, 1, buf); + LogMessageVerbSigSafe(X_ERROR, 1, buf); read_log_msg(logmsg); assert(strcmp(&logmsg[strlen(logmsg) - 3], "en\n") == 0); /* same thing, this time as string substitution */ - LogMessageVerb(X_ERROR, 1, "%s", buf); + LogMessageVerbSigSafe(X_ERROR, 1, "%s", buf); read_log_msg(logmsg); assert(strcmp(&logmsg[strlen(logmsg) - 3], "en\n") == 0); /* strings containing placeholders should just work */ - LogMessageVerb(X_ERROR, 1, "%s\n", str); + LogMessageVerbSigSafe(X_ERROR, 1, "%s\n", str); read_log_msg(logmsg); assert(strcmp(logmsg, "(EE) %s %d %u %% %p %i\n") == 0); /* literal % */ - LogMessageVerb(X_ERROR, 1, "test %%\n"); + LogMessageVerbSigSafe(X_ERROR, 1, "test %%\n"); read_log_msg(logmsg); assert(strcmp(logmsg, "(EE) test %\n") == 0); /* character */ - LogMessageVerb(X_ERROR, 1, "test %c\n", 'a'); + LogMessageVerbSigSafe(X_ERROR, 1, "test %c\n", 'a'); read_log_msg(logmsg); assert(strcmp(logmsg, "(EE) test a\n") == 0); /* something unsupported % */ - LogMessageVerb(X_ERROR, 1, "test %Q\n"); + LogMessageVerbSigSafe(X_ERROR, 1, "test %Q\n"); read_log_msg(logmsg); assert(strstr(logmsg, "BUG") != NULL); - LogMessageVerb(X_ERROR, 1, "\n"); + LogMessageVerbSigSafe(X_ERROR, 1, "\n"); fseek(f, 0, SEEK_END); /* string substitution */ - LogMessageVerb(X_ERROR, 1, "%s\n", "substituted string"); + LogMessageVerbSigSafe(X_ERROR, 1, "%s\n", "substituted string"); read_log_msg(logmsg); assert(strcmp(logmsg, "(EE) substituted string\n") == 0); /* Invalid format */ - LogMessageVerb(X_ERROR, 1, "%4", 4); + LogMessageVerbSigSafe(X_ERROR, 1, "%4", 4); read_log_msg(logmsg); assert(strcmp(logmsg, "(EE) ") == 0); - LogMessageVerb(X_ERROR, 1, "\n"); + LogMessageVerbSigSafe(X_ERROR, 1, "\n"); fseek(f, 0, SEEK_END); /* %hld is bogus */ - LogMessageVerb(X_ERROR, 1, "%hld\n", 4); + LogMessageVerbSigSafe(X_ERROR, 1, "%hld\n", 4); read_log_msg(logmsg); assert(strstr(logmsg, "BUG") != NULL); - LogMessageVerb(X_ERROR, 1, "\n"); + LogMessageVerbSigSafe(X_ERROR, 1, "\n"); fseek(f, 0, SEEK_END); /* number substitution */ @@ -262,12 +262,12 @@ static void logging_format(void) do { char expected[30]; sprintf(expected, "(EE) %u\n", ui); - LogMessageVerb(X_ERROR, 1, "%u\n", ui); + LogMessageVerbSigSafe(X_ERROR, 1, "%u\n", ui); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); sprintf(expected, "(EE) %x\n", ui); - LogMessageVerb(X_ERROR, 1, "%x\n", ui); + LogMessageVerbSigSafe(X_ERROR, 1, "%x\n", ui); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); @@ -281,21 +281,21 @@ static void logging_format(void) do { char expected[30]; sprintf(expected, "(EE) %lu\n", lui); - LogMessageVerb(X_ERROR, 1, "%lu\n", lui); + LogMessageVerbSigSafe(X_ERROR, 1, "%lu\n", lui); read_log_msg(logmsg); sprintf(expected, "(EE) %lld\n", (unsigned long long)ui); - LogMessageVerb(X_ERROR, 1, "%lld\n", (unsigned long long)ui); + LogMessageVerbSigSafe(X_ERROR, 1, "%lld\n", (unsigned long long)ui); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); sprintf(expected, "(EE) %lx\n", lui); - LogMessageVerb(X_ERROR, 1, "%lx\n", lui); + LogMessageVerbSigSafe(X_ERROR, 1, "%lx\n", lui); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); sprintf(expected, "(EE) %llx\n", (unsigned long long)ui); - LogMessageVerb(X_ERROR, 1, "%llx\n", (unsigned long long)ui); + LogMessageVerbSigSafe(X_ERROR, 1, "%llx\n", (unsigned long long)ui); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); @@ -310,12 +310,12 @@ static void logging_format(void) do { char expected[30]; sprintf(expected, "(EE) %d\n", i); - LogMessageVerb(X_ERROR, 1, "%d\n", i); + LogMessageVerbSigSafe(X_ERROR, 1, "%d\n", i); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); sprintf(expected, "(EE) %d\n", i | INT_MIN); - LogMessageVerb(X_ERROR, 1, "%d\n", i | INT_MIN); + LogMessageVerbSigSafe(X_ERROR, 1, "%d\n", i | INT_MIN); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); @@ -329,22 +329,22 @@ static void logging_format(void) do { char expected[30]; sprintf(expected, "(EE) %ld\n", li); - LogMessageVerb(X_ERROR, 1, "%ld\n", li); + LogMessageVerbSigSafe(X_ERROR, 1, "%ld\n", li); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); sprintf(expected, "(EE) %ld\n", li | LONG_MIN); - LogMessageVerb(X_ERROR, 1, "%ld\n", li | LONG_MIN); + LogMessageVerbSigSafe(X_ERROR, 1, "%ld\n", li | LONG_MIN); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); sprintf(expected, "(EE) %lld\n", (long long)li); - LogMessageVerb(X_ERROR, 1, "%lld\n", (long long)li); + LogMessageVerbSigSafe(X_ERROR, 1, "%lld\n", (long long)li); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); sprintf(expected, "(EE) %lld\n", (long long)(li | LONG_MIN)); - LogMessageVerb(X_ERROR, 1, "%lld\n", (long long)(li | LONG_MIN)); + LogMessageVerbSigSafe(X_ERROR, 1, "%lld\n", (long long)(li | LONG_MIN)); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); @@ -357,7 +357,7 @@ static void logging_format(void) /* pointer substitution */ /* we print a null-pointer differently to printf */ - LogMessageVerb(X_ERROR, 1, "%p\n", NULL); + LogMessageVerbSigSafe(X_ERROR, 1, "%p\n", NULL); read_log_msg(logmsg); assert(strcmp(logmsg, "(EE) 0x0\n") == 0); @@ -369,7 +369,7 @@ static void logging_format(void) #else sprintf(expected, "(EE) %p\n", (void*)ptr); #endif - LogMessageVerb(X_ERROR, 1, "%p\n", (void*)ptr); + LogMessageVerbSigSafe(X_ERROR, 1, "%p\n", (void*)ptr); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); ptr <<= 1; @@ -380,20 +380,20 @@ static void logging_format(void) double d = float_tests[i]; char expected[30]; sprintf(expected, "(EE) %.2f\n", d); - LogMessageVerb(X_ERROR, 1, "%f\n", d); + LogMessageVerbSigSafe(X_ERROR, 1, "%f\n", d); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); /* test for length modifiers, we just ignore them atm */ - LogMessageVerb(X_ERROR, 1, "%.3f\n", d); + LogMessageVerbSigSafe(X_ERROR, 1, "%.3f\n", d); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); - LogMessageVerb(X_ERROR, 1, "%3f\n", d); + LogMessageVerbSigSafe(X_ERROR, 1, "%3f\n", d); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); - LogMessageVerb(X_ERROR, 1, "%.0f\n", d); + LogMessageVerbSigSafe(X_ERROR, 1, "%.0f\n", d); read_log_msg(logmsg); assert(strcmp(logmsg, expected) == 0); }