Re: [PATCH v3 3/7] kunit: Handle logging of lines longer than the fragment buffer size

Rae Moar
2023-08-10T22:41:52Z

On Thu, Aug 10, 2023 at 9:38 AM David Gow <davidgow@google.com> wrote:
>
> On Wed, 9 Aug 2023 at 23:54, Richard Fitzgerald
> <rf@opensource.cirrus.com> wrote:
> >
> > Add handling to kunit_log_append() for log messages that are longer than
> > a single buffer fragment.
> >
> > The initial implementation of fragmented buffers did not change the logic
> > of the original kunit_log_append(). A consequence was that it still had
> > the original assumption that a log line will fit into one buffer.
> >
> > This patch checks for log messages that are larger than one fragment
> > buffer. In that case, kvasprintf() is used to format it into a temporary
> > buffer and that content is then split across as many fragments as
> > necessary.
> >
> > Signed-off-by: Richard Fitzgerald <rf@opensource.cirrus.com>
> > ---
>
> I think this looks good (and is a long-overdue addition to the logging
> functionality).
>
> One thought I have (and I'm kicking myself for not thinking of it
> earlier) is that this is starting to get very similar to the "string
> stream" functionality in lib/kunit/string-stream.{h,c}. Now, I
> actually think this implementation is much more efficient (using
> larger fragments, whereas the string stream uses variable-sized ones).
> Particularly since there are a lot of cases where string streams are
> created, converted to a string, and then logged, there's almost
> certainly a bunch of redundant work being done here.
>
> My gut feeling is that we should stick with this as-is, and maybe try
> to either work out some better integration between string streams and
> logging (to avoid that extra string allocation) or find some way of
> combining them.
>
> Regardless, this seems good as-is to me. There are some minor comments
> below, but nothing disastrous. I'll let Rae have a look over the
> various strscpy and strlcat calls, though, as while I did check them
> carefully (and KASAN hasn't complained), it's always best to have as
> many eyes on C string code as possible. :-)
>

Hello!

I have tested and taken a look at this and it looks overall good to
me. I think all of the string copying and concatenating is right.

Other than David's comments below, especially whether we should do
this with string-stream, I am pretty happy to accept this as is.

Thanks!
Rae

> But in my eyes, this is
> Reviewed-by: David Gow <davidgow@google.com>
>
> Cheers,
> -- David
>
> > lib/kunit/test.c | 65 +++++++++++++++++++++++++++++++++++++++++++++---
> > 1 file changed, 61 insertions(+), 4 deletions(-)
> >
> > diff --git a/lib/kunit/test.c b/lib/kunit/test.c
> > index dfe51bc2b387..28d0048d6171 100644
> > --- a/lib/kunit/test.c
> > +++ b/lib/kunit/test.c
> > @@ -140,25 +140,82 @@ static struct kunit_log_frag *kunit_log_extend(struct list_head *log)
> > return frag;
> > }
> >
> > +static void kunit_log_append_string(struct list_head *log, const char *src)
> > +{
> > + struct kunit_log_frag *frag, *new_frag;
> > + int log_len, bytes_left;
> > + ssize_t written;
> > + char *p;
> > +
> > + frag = list_last_entry(log, struct kunit_log_frag, list);
> > + log_len = strlen(frag->buf);
> > + bytes_left = sizeof(frag->buf) - log_len;
> > +
> > + written = strscpy(frag->buf + log_len, src, bytes_left);
> > + if (written != -E2BIG)
> > + goto newline;
> > +
> > + src += bytes_left - 1;
> > + do {
> > + new_frag = kunit_log_extend(log);
> > + if (!new_frag)
> > + goto newline;
> > +
> > + frag = new_frag;
> > + written = strscpy(frag->buf, src, sizeof(frag->buf));
> > + src += sizeof(frag->buf) - 1;
> > + } while (written == -E2BIG);
> > +
> > +newline:
> > + if (written == -E2BIG)
>
> I think that this can only be true if kunit_log_extend() fails. If the
> do/while loop ends naturally, then written != -E2BIG, as is the case
> with the strscpy goto above.
>
> Do you think it's cleaner to move the 'written = strlen(frag->buf)
> into the if (!new_frag) statement within the loop?
>
> > + written = strlen(frag->buf);
> > +
> > + p = &frag->buf[written - 1];
> > + if (*p != '\n') {
> > + if (strlcat(frag->buf, "\n", sizeof(frag->buf)) >= sizeof(frag->buf)) {
> > + frag = kunit_log_extend(log);
> > + if (!frag) {
>
> A comment here could be useful. Something like "If we can't extend the
> log to add a newline, truncate the last message".
>
> > + *p = '\n';
> > + return;
> > + }
> > +
> > + frag->buf[0] = '\n';
> > + frag->buf[1] = '\0';
> > + }
> > + }
> > +}
> > +
> > /* Append formatted message to log, extending the log buffer if necessary. */
> > void kunit_log_append(struct list_head *log, const char *fmt, ...)
> > {
> > va_list args;
> > struct kunit_log_frag *frag;
> > int len, log_len, len_left;
> > + char *tmp = NULL;
> >
> > if (!log)
> > return;
> >
> > - frag = list_last_entry(log, struct kunit_log_frag, list);
> > - log_len = strlen(frag->buf);
> > - len_left = sizeof(frag->buf) - log_len - 1;
> > -
> > /* Evaluate length of line to add to log */
> > va_start(args, fmt);
> > len = vsnprintf(NULL, 0, fmt, args) + 1;
> > va_end(args);
> >
> > + if (len > sizeof(frag->buf) - 1) {
> > + va_start(args, fmt);
> > + tmp = kvasprintf(GFP_KERNEL, fmt, args);
> > + va_end(args);
> > +
>
> Should we handle the case where kvasprintf() fails here and drop the
> log message?
>
>
> > + kunit_log_append_string(log, tmp);
> > + kfree(tmp);
> > +
> > + return;
> > + }
> > +
> > + frag = list_last_entry(log, struct kunit_log_frag, list);
> > + log_len = strlen(frag->buf);
> > + len_left = sizeof(frag->buf) - log_len - 1;
> > +
> > if (len > len_left) {
> > frag = kunit_log_extend(log);
> > if (!frag)
> > --
> > 2.30.2
> >