Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Message-ID: <371a6ba0-c076-8e44-ae2f-32429de507da@opensource.cirrus.com>
Date:   Wed, 9 Aug 2023 10:39:39 +0100
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:102.0) Gecko/20100101
 Thunderbird/102.14.0
Subject: Re: [PATCH v2 2/6] kunit: kunit-test: Add test cases for extending
 log buffer
To:     Rae Moar <rmoar@google.com>
CC:     <brendan.higgins@linux.dev>, <davidgow@google.com>,
        <linux-kselftest@vger.kernel.org>, <kunit-dev@googlegroups.com>,
        <linux-kernel@vger.kernel.org>, <patches@opensource.cirrus.com>
References: <20230808123529.4725-1-rf@opensource.cirrus.com>
 <20230808123529.4725-3-rf@opensource.cirrus.com>
 <CA+GJov79EJLbdptX+hhTqa90C7A0aJ-wzjxF1LDn++jWHeNXFA@mail.gmail.com>
Content-Language: en-US
From:   Richard Fitzgerald <rf@opensource.cirrus.com>
In-Reply-To: <CA+GJov79EJLbdptX+hhTqa90C7A0aJ-wzjxF1LDn++jWHeNXFA@mail.gmail.com>
Content-Type: text/plain; charset="UTF-8"; format=flowed
Content-Transfer-Encoding: 8bit
Precedence: bulk

On 8/8/23 22:16, Rae Moar wrote:
> On Tue, Aug 8, 2023 at 8:35 AM Richard Fitzgerald
> <rf@opensource.cirrus.com> wrote:
>>
>> Add test cases for the dynamically-extending log buffer.
>>
>> kunit_log_extend_test_1() logs a series of numbered lines then tests
>> that the resulting log contains all the lines.
>>
>> kunit_log_extend_test_2() logs a large number of lines of varying length
>> to create many fragments, then tests that all lines are present.
>>
>> kunit_log_frag_sized_line_test() logs a line that exactly fills a
>> fragment. This should not cause an extension of the log or truncation
>> of the line.
>>
>> kunit_log_newline_test() has a new test to append a line that is exactly
>> the length of the available space in the current fragment and check that
>> the resulting log has a trailing '\n'.
>>
>> Signed-off-by: Richard Fitzgerald <rf@opensource.cirrus.com>
> 
> Hello!
> 
> I am happy to see so many tests in this patch series. I've been
> working with these patches and the debugfs logs seem to be working
> well.
> 
> However, when I ran the new kunit-log-test tests three of the tests
> failed: kunit_log_extend_test_1(), kunit_log_extend_test_2(), and
> kunit_log_newline_test().
> 
> The diagnostic info for kunit_log_extend_test_1() reports:
> 
> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:705
> [20:55:27] Expected p == line, but
> [20:55:27]     p == "xxxxxx…xxxx12345678"
> [20:55:27]     line == "The quick brown fox jumps over the lazy penguin 0"
> …
> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:705
> [20:55:27] Expected p == line, but
> [20:55:27]     p == "The quick brown fox jumps over the lazy penguin 1"
> [20:55:27]     line == "The quick brown fox jumps over the lazy penguin 4"
> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:705
> [20:55:27] Expected p == line, but
> [20:55:27]     p == "The quick brown fox jumps over the lazy penguin 2"
> [20:55:27]     line == "The quick brown fox jumps over the lazy penguin 5"
> …
> [20:55:27] # kunit_log_extend_test_1: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:709
> [20:55:27] Expected i == num_lines, but
> [20:55:27]     i == 64 (0x40)
> [20:55:27]     num_lines == 141 (0x8d)
> 
> So it looks like the log contains a different number of lines than
> expected which is causing the difference of 3 between expected and
> what was obtained. Potentially the log is not getting cleared/freed
> properly in between test cases?
> 
> The diagnostic info for kunit_log_extend_test_2() reports:
> 
> [20:55:27]     # kunit_log_extend_test_2: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:776
> [20:55:27]     Expected p == &line[i], but
> [20:55:27]         p ==
> "xxxxx...xxxxx123456780123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
> [20:55:27]         &line[i] ==
> "0123456789abcdef101112131415161718191a1b1c1d1e1f202122232425262728292a2b2c2d2e2f30313233343536373839"
> [20:55:27]     # kunit_log_extend_test_2: EXPECTATION FAILED at
> lib/kunit/kunit-test.c:781
> [20:55:27]     Expected n == num_lines, but
> [20:55:27]         n == 147 (0x93)
> [20:55:27]         num_lines == 155 (0x9b)
> [20:55:27] Not enough lines.
> 
> Similar difference in the number of lines here.
> 
> The diagnostic info for kunit_log_newline_test() reports that the test
> fails on this line:
> 
> KUNIT_EXPECT_EQ(test, p[strlen(p) - 1], '\n');
> 
> Let me know if you are seeing similar errors. I can post the full log
> if that would be helpful.
> 
> -Rae
> 

Ah, I see a bug in get_concatenated_log().
Does this change fix it for you?

	len++; /* for terminating '\0' */
-	p = kunit_kmalloc(test, len, GFP_KERNEL);
+	p = kunit_kzalloc(test, len, GFP_KERNEL);