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

[Rae Moar]

On Thu, Aug 10, 2023 at 9:38 AM David Gow <davidgow@xxxxxxxxxx> wrote:
>
> On Wed, 9 Aug 2023 at 23:54, Richard Fitzgerald
> <rf@xxxxxxxxxxxxxxxxxxxxx> 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@xxxxxxxxxxxxxxxxxxxxx>
> > ---
>
> 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@xxxxxxxxxx>
>
> 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
> >