On 17 December 2014 at 17:19, Chris Wilson <chris@xxxxxxxxxxxxxxxxxx> wrote:
> On Wed, Dec 17, 2014 at 04:45:43PM +0000, Thomas Wood wrote:
>> Print recent log entries if a test or subtest fails and the current log
>> level is set to info.
>>
>> v2: Write log to stderr after test or subtest failure and make log
>> buffering thread safe.
>>
>> Signed-off-by: Thomas Wood <thomas.wood@xxxxxxxxx>
>> ---
>> lib/igt_core.c | 103 +++++++++++++++++++++++++++++++++++++++++++++++++++++----
>> 1 file changed, 96 insertions(+), 7 deletions(-)
>>
>> diff --git a/lib/igt_core.c b/lib/igt_core.c
>> index 08e0c47..457b3b1 100644
>> --- a/lib/igt_core.c
>> +++ b/lib/igt_core.c
>> @@ -50,6 +50,8 @@
>> #include <termios.h>
>> #include <errno.h>
>> #include <time.h>
>> +#include <limits.h>
>> +#include <pthread.h>
>>
>> #include "drmtest.h"
>> #include "intel_chipset.h"
>> @@ -228,8 +230,18 @@ enum {
>> OPT_HELP = 'h'
>> };
>>
>> +static const char *command_str;
>> +static int igt_exitcode = IGT_EXIT_SUCCESS;
>> +
>> static char* igt_log_domain_filter;
>>
>> +static struct {
>> + char *entries[256];
>> + uint8_t start, end;
>> +} log_buffer;
>> +static pthread_mutex_t log_buffer_mutex = PTHREAD_MUTEX_INITIALIZER;
>> +
>> +
>> __attribute__((format(printf, 1, 2)))
>> static void kmsg(const char *format, ...)
>> #define KERN_EMER "<0>"
>> @@ -353,6 +365,52 @@ static void low_mem_killer_disable(bool disable)
>> chmod(adj_fname, buf.st_mode);
>> }
>>
>> +#define write_log_msg(x) write(STDERR_FILENO, x, strlen(x))
>> +
>> +/* this function must be safe to be called inside a signal handler */
>> +static void write_log(void)
>> +{
>> + uint8_t i;
>> + char *last_line;
>> +
>> + pthread_mutex_lock(&log_buffer_mutex);
>> +
>> + /* don't write an empty log */
>> + if (log_buffer.start == log_buffer.end) {
>> + pthread_mutex_unlock(&log_buffer_mutex);
>> + return;
>> + }
>> +
>> + if (in_subtest) {
>> + write_log_msg("--- Subtest ");
>> + write_log_msg(in_subtest);
>> + } else {
>> + write_log_msg("--- Test ");
>> + write_log_msg(command_str);
>> + }
>> + write_log_msg(" failed.\n");
>> + write_log_msg("--- Log Start\n");
>> +
>> + i = log_buffer.start;
>> + do {
>> + last_line = log_buffer.entries[i];
>> + write_log_msg(last_line);
>
> What happens if nothing is in the log:
> log_buffer.start == log_buffer.end == 0
>
> last_line[pos] is a *NULL, as may strlen(NULL).
>
> When something is in the log, start != end, so this can just be a simple
>
> if (log_buffer.start == log_buffer.end)
> return;
Yes, this check is done at the start of the function.
>
> i = log_buffer.start;
> do {
>> +
>> + /* ensure each line ends in a newline */
>> + for (int pos = 0; last_line[pos] != '\0'; pos++) {
>> + if (last_line[pos] != '\n'
>> + && last_line[pos + 1] == '\0')
>> + write_log_msg("\n");
>> + }
>
> pos = strlen(last_line);
> if (pos > 0 && last_line[pos-1] != '\n')
> write_log_msg("\n");
The for loop above was to avoid using strlen (which is not listed as
signal safe), but strlen is being used in write_log_msg, so this would
need further work to make it safe too.
>
> if (i == log_buffer.end)
> break;
>
> i++;
> } while (1);
>
> It's not the neatest of loops, but it should be effective.
>
>> + i++;
>> + } while (i != log_buffer.start && i != log_buffer.end);
>> +
>> + write_log_msg("--- Log End\n");
>
> After it has dumped the log, do you want to reset the log_buffer?
> i.e. log_buffer.start = log_buffer.end;
Yes, this is added in patch 4 of this series.
>
>> + pthread_mutex_unlock(&log_buffer_mutex);
>
> I was worried by taking locks inside a signal handler, but this looks
> like it could be made safe, and with a bit more work, you can make the
> other half robust as well:
Yes, this is problematic. It will probably be worth adding some
library test cases to try and ensure the default signal handlers are
as safe as possible.
>
> char *new, *old;
>
> asprintf(&new,
> "(%s:%d) %s%s%s: %s",
> program_name, getpid(),
> (domain) ? domain : "",
> (domain) ? "-" : "",
> igt_log_level_str[level],
> line);
>
> pthread_mutex_lock(&log_buffer_mutex);
> old = log_buffer.entries[log_buffer.end];
> log_bufffer.entries[log_buffer.end] = new;
> if (++log_buffer.end == log_buffer.start)
> log_buffer.start++;
> pthread_mutex_unlock(&log_buffer_mutex);
>
> free(old);
>
> i.e. only do the pointer head/tail assignment inside the lock to
> minimise exposure.
> -Chris
>
> --
> Chris Wilson, Intel Open Source Technology Centre
> _______________________________________________
> Intel-gfx mailing list
> Intel-gfx@xxxxxxxxxxxxxxxxxxxxx
> http://lists.freedesktop.org/mailman/listinfo/intel-gfx
_______________________________________________
Intel-gfx mailing list
Intel-gfx@xxxxxxxxxxxxxxxxxxxxx
http://lists.freedesktop.org/mailman/listinfo/intel-gfx
