[PATCH i-g-t] lib/igt_core: Free log_buffer entries on exit

[Lucas De Marchi]

On Thu, Nov 07, 2024 at 06:31:45PM +0100, Kamil Konieczny wrote:
>Hi Lucas,
>On 2024-11-06 at 23:02:08 -0800, Lucas De Marchi wrote:
>> Make sure the buffer entries are released, otherwise valgrind output
>> becomes each used entry as still reachable on exit (up to 256).
>>
>> Test:
>> 	# valgrind --leak-check=full  ./build/tests/xe_live_ktest  --r xe_mocs
>>
>> Before:
>> 	==16082== LEAK SUMMARY:
>> 	==16082==    definitely lost: 0 bytes in 0 blocks
>> 	==16082==    indirectly lost: 0 bytes in 0 blocks
>> 	==16082==      possibly lost: 0 bytes in 0 blocks
>> 	==16082==    still reachable: 33,473 bytes in 59 blocks
>>
>> After:
>> 	==15992== LEAK SUMMARY:
>> 	==15992==    definitely lost: 0 bytes in 0 blocks
>> 	==15992==    indirectly lost: 0 bytes in 0 blocks
>> 	==15992==      possibly lost: 0 bytes in 0 blocks
>> 	==15992==    still reachable: 31,083 bytes in 42 blocks
>
>Thank you for a patch, there are still some blocks left,
>maybe because that buffer is a ring? e.g. it could have
>end < start

no, those blocks are other things.

Note that we are looping with a uint8_t. When we have start == 250
and end == 2 (impossible due to how we place log messages, but just for
illustration), it's expected to free the positions [250, 255], [0, 1].

Some more context explanation of this change.

I sent this because the first leaks I was seeing were related to libkmod
and as the libkmod maintainer I was curious if it was a leak in libkmod
that was getting masked by us not releasing its ctx. It was not, and
just releasing the ctx (see
https://patchwork.freedesktop.org/patch/623301/?series=140746&rev=3)
made those go away.  While doing that and running other more log-heavy
tests, I was getting a flood of these 256 blocks, so I fixed that just
to get them out of the way of what I was really after.

Looking back to this patch, not sure there's much value as whatever
binary using it is already on its way out.

>
>>
>> Signed-off-by: Lucas De Marchi <lucas.demarchi at intel.com>
>> ---
>>  lib/igt_core.c | 15 ++++++++++++---
>>  1 file changed, 12 insertions(+), 3 deletions(-)
>>
>> diff --git a/lib/igt_core.c b/lib/igt_core.c
>> index 407f7b551..879d1ecd8 100644
>> --- a/lib/igt_core.c
>> +++ b/lib/igt_core.c
>> @@ -469,11 +469,21 @@ static void _igt_log_buffer_append(char *line)
>>  	pthread_mutex_unlock(&log_buffer_mutex);
>>  }
>>
>> +static void _igt_log_buffer_reset_locked(void)
>> +{
>> +	for (; log_buffer.start != log_buffer.end; log_buffer.start++) {
>> +		free(log_buffer.entries[log_buffer.start]);
>> +		log_buffer.entries[log_buffer.start] = NULL;
>> +	}
>
>Here you should use the same loop as in _dump, so
>
>	i = log_buffer.start;
>	do {
>		// do ops here
>		i++;
>        } while (i != log_buffer.start && i != log_buffer.end);

there's an off-by-one bug in this loop that I didn't want to reproduce
here: if we never ever logged anything, at the beggining start == end == 0,
and in the first check i == 1. Which means we will print (or free in
this case) the 256 entries. Oops.  I think we always log at least the
test name, so it's not a bug we reproduce.

>
>Or even simpler, init with NULLs and then just free all?

it's a static variable, it's already zero initialized.

>For example, if start=2, end=1, there is still a valid pointer
>at end==1

no, end marks where the *next* entry will be. At the beginning we have:

start == end == 0. There are no entries in the ringbuffer.

After the first logged message:
start == 0, end == 1.

If the ringbuffer ever wraps, then we will always have:

start == x + 1; end == x, or
start == 0; end == 255

Except for when dumping the contents, this ringbuffer doesn't have any
consumer incrementing the start AFAICS.

>
>Or do one more ops for case 'end < start'

in the wrap case, see above. The key of the implementation is that we
are using a uint8_t and relying on it wrapping back to 0, so we can just
increment the head until it reaches the tail.

As said above, there isn't much value in this patch other than "let's
get it right", so consider it optional.


Lucas De Marchi

>
>Regards,
>Kamil
>
>> +
>> +	log_buffer.start = log_buffer.end = 0;
>> +}
>> +
>>  static void _igt_log_buffer_reset(void)
>>  {
>>  	pthread_mutex_lock(&log_buffer_mutex);
>>
>> -	log_buffer.start = log_buffer.end = 0;
>> +	_igt_log_buffer_reset_locked();
>>
>>  	pthread_mutex_unlock(&log_buffer_mutex);
>>  }
>> @@ -624,8 +634,7 @@ static void _igt_log_buffer_dump(void)
>>  		i++;
>>  	} while (i != log_buffer.start && i != log_buffer.end);
>>
>> -	/* reset the buffer */
>> -	log_buffer.start = log_buffer.end = 0;
>> +	_igt_log_buffer_reset_locked();
>>
>>  	_log_line_fprintf(stderr, "****  END  ****\n");
>>  	pthread_mutex_unlock(&log_buffer_mutex);
>> --
>> 2.47.0
>>