[PATCH v2 00/14] Fix signal-unsafe logging
Daniel Kurtz
djkurtz at google.com
Fri Apr 13 01:34:36 PDT 2012
On Fri, Apr 13, 2012 at 9:09 AM, Peter Hutterer
<peter.hutterer at who-t.net> wrote:
> On Wed, Apr 11, 2012 at 06:33:26PM -0700, Chase Douglas wrote:
>> On 04/11/2012 04:53 PM, Peter Hutterer wrote:
>> > On Mon, Apr 09, 2012 at 11:17:26AM -0700, Chase Douglas wrote:
>> >> This new patch set includes a few fixes to the first and many more fixed
>> >> logging paths. All paths in the server that occur when it encounters a
>> >> fatal signal are now handled properly.
>> >>
Hi Chase,
I just started looking at the os/log.c in the X server again to fix an
unrelated issue, and realized that my patches from last year did not,
in fact, make logging safe to do from signal handlers. I am really
glad you are looking into fixing this!
However, I have a more basic question. Why does the X server process
input events in signal handlers the first place?
Why not just add the event device files to a read file set in the main
"WaitForSomething" select loop, and then call the appropriate driver
ReadInput from normal process context?
The X server must be using SigIO for some really good reasons, what are they?
-Daniel
>> >> I do not think this affects the crash I have been seeing in the Ubuntu
>> >> server. I tracked that issue down to a bug in the synaptics input
>> >> module. Since the only known issue is that running the server under
>> >> valgrind may fail if messages are logged inappropriately, I suggest we
>> >> not apply this to any stable branches.
>> >>
>> >> The full tree is still maintained at:
>> >>
>> >> http://cgit.freedesktop.org/~cndougla/xserver/log/?h=signal-logging
>> >>
>> >> Thanks!
>> >
>> > Looks good and this is certainly needed. I do have a few comments though:
>> >
>> > - I'd really like to see some tests of these new functions. Should be easy
>> > enough to write, given that they're all exposed and you can use strlen,
>> > strcmp, etc. to compare results.
>> > Plus, you should be able to test them inside a signal handler too with
>> > little effort.
>>
>> Some of the functions definitely could use tests, like strlen_sigsafe().
>> I'll add some.
>>
>> However, I don't know if it's possible to add tests for behavior inside
>> a signal handler. For a test to be useful it must be repeatable and fail
>> every time it's wrong. Usually signal context corruption is
>> indeterminate. Maybe it could be repeatable with the use of valgrind,
>> but even then I'm not 100% sure.
>>
>> > - AFAICT, every single caller to LogMessageVerbSigSafe uses -1 as verbosity.
>> > How about a LogMessageSigSafe wrapper?
>>
>> There are a few places where I replaced non-ErrorF calls, where the
>> verbosity remains 1 instead of -1.
>>
>> I thought about creating a non-verb wrapper, but I didn't really have
>> much of an interest in reproducing all the different logging macros and
>> variations we currently have. The idea is that logging in signal context
>> should be fairly infrequent, and if you need it then you can get along
>> with all the args.
>
> It should be infrequent, but any error between ReadInput and mieqEnqueue will
> require it. That may not happen often, but the code still needs to be there.
> So a sensible API is something we should definitely aim for.
>
>> Secondarily, what would you default to? ErrorF uses -1, but LogMessage
>> uses 1.
>
> There's a reason that ErrorF is different (albeit just a wrapper) to
> LogMessage - it makes the code more obvious. A LogMessageVerb(..., -1, ...)
> is much less obvious and grep-able than ErrorF(). So at least having
> ErrorFSigSafe() is a good thing to have. It would make any new code stick
> out. "Hey, it's ErrorFSigSafe up there, but ErrorF here - one of them is
> wrong".
>
>> > - the API is rather shocking, replacing one vararg function with a number of
>> > mixed calls makes it really hard to grep for the message.
>> > a poor man's printf parsing that searches for %d, %s and %x would help
>> > here.
>>
>> Variadic argument implementation is some of the blackest magic of C
>> code, and varies a great deal even between architectures of glibc. I
>> don't know if we can be sure that variadic arguments will always be
>> signal safe. They aren't mentioned in the POSIX signal(7) man page as
>> safe functions.
>>
>> I doubt we would actually support Interix SUA, for example, but it is
>> POSIX compliant and its man page says va_* functions are not signal
>> safe: http://www.suacommunity.com/man/3/varargs.3.html.
>
> yeah, unfortunately that's the only documentation I found too, nothing else
> seems to hints at whether it's signal safe or not.
>
> If we can't use varargs, we really need to re-do the error messages to be
> less clunky. e.g.
>
> LogMessageVerbSigSafe(X_NONE, -1,
> "Please also check the log file at \"");
> LogMessageVerbSigSafe(X_NONE, -1, xf86LogFile);
> LogMessageVerbSigSafe(X_NONE, -1, " for additional
> information.\n");
>
> can be
> LogMessaveVerbSigSafe("For additional information see the log file at );
> LogMessaveVerbSigSafe(xf86LogFile);
> which makes it a lot more grep-able. Or, something like this below. Uncompiled,
> just a quick write, so don't expect this to work, it's just to illustrate:
>
> typedef union {
> uint32_t ui;
> int32_t i;
> char *c;
> const char *str;
> void *ptr;
> } log_param_t;
>
> /* Log a message using only signal safe functions. */
> void
> LogMessageVerbSigSafe(MessageType type, int verb, const char *message,
> log_param_t* param)
> {
> const char *type_str;
> int param_idx = 0;
> int begin, end;
> int slen;
> char number[20];
> int i;
>
> type_str = LogMessageTypeVerbString(type, verb);
> if (!type_str)
> return;
>
> if (type_str[0] != '\0') {
> write(logFileFd, type_str, strlen_sigsafe(type_str));
> write(logFileFd, " ", 1);
> }
>
> begin = end = 0;
> slen = strlen_sigsafe(message);
>
> for (i = 0; i < slen; i++, end++) {
> if (i < begin)
> continue;
>
> if (message[i] != '%')
> continue;
>
> /* We found a %, it's not a %% escape, log message from last stop to
> * here before attempting replacements */
> if (begin != end &&
> i < slen - 1 && message[i + 1] != '%') {
> write(logFileFd, &message[begin], end - begin);
> begin = i + 1;
> }
>
> switch (message[i + 1]) {
> case 'd':
> case 'u':
> FormatUInt64(param[param_idx].ui, number);
> break;
> case 'x':
> FormatUInt64Hex(param[param_idx].ui, number);
> break;
> case 'c':
> write(logFileFd, ¶m[param_idx].c, 1);
> break;
> case 's':
> write(logFileFd, param[param_idx].str,
> a> strlen_sigsafe(param[param_idx].str));
> break;
> default: /* FIXME: error msg */
> break;
> }
>
> param_idx++;
> }
>
>
> write(logFileFd, message, strlen_sigsafe(message));
> fsync(logFileFd);
> }
>
> Instead of varargs, the callers need to supply a log_param_t array, which is
> painful, but hopefully better than splitting log messages over several commands.
>
> Cheers,
> Peter
>
>> > - given that input drivers almost always use signal-sensitive processing,
>> > making xf86IDrvMsg signal safe would go a long way
>>
>> It's variadic, so I don't think that will be possible. I know there's
>> bound to be some pain here that reaches device drivers, but I don't see
>> a way around it.
>>
>> -- Chase
> _______________________________________________
> xorg-devel at lists.x.org: X.Org development
> Archives: http://lists.x.org/archives/xorg-devel
> Info: http://lists.x.org/mailman/listinfo/xorg-devel
--
Daniel Kurtz | Software Engineer | djkurtz at google.com | 650.204.0722
More information about the xorg-devel
mailing list