Re: [fs] 54cc07a761: BUG: kernel test crashed

Re: [fs] 54cc07a761: BUG: kernel test crashed

[Eric W. Biederman]

kernel test robot <xiaolong.ye@intel.com> writes:

> FYI, we noticed the following commit:
>
> https://git.kernel.org/pub/scm/linux/kernel/git/ebiederm/user-namespace.git for-testing
> commit 54cc07a761deb38318aca64ddf07fc45157c85e0 ("fs: Call d_automount with the filesystems creds")
>
> in testcase: boot
>
> on test machine: 1 threads qemu-system-x86_64 -enable-kvm -cpu Westmere with 320M memory
>
> caused below changes:
>
>
> +-------------------------+------------+------------+
> |                         | 8175435777 | 54cc07a761 |
> +-------------------------+------------+------------+
> | boot_successes          | 102        | 16         |
> | boot_failures           | 0          | 3          |
> | BUG:kernel_test_crashed | 0          | 3          |
> | timestamp.last          | 0          | 54.951425  |
> +-------------------------+------------+------------+

The problem here seems to be the line: "BUG: kernel test crashed"
Can someone give me some clarity on what that refers to?

My experience in the last week indicates I can't trust the commit the
test bot tells me is the problem commit on these tests.  So if there is
an issue I need something more to track it down with than a line of
output I don't have the source to.

Eric

More information please. Re: [fs] 54cc07a761: BUG: kernel test crashed

[Eric W. Biederman]

kernel test robot <xiaolong.ye@intel.com> writes:

> FYI, we noticed the following commit:
>
> https://git.kernel.org/pub/scm/linux/kernel/git/ebiederm/user-namespace.git for-testing
> commit 54cc07a761deb38318aca64ddf07fc45157c85e0 ("fs: Call d_automount with the filesystems creds")
>
> in testcase: boot
>
> on test machine: 1 threads qemu-system-x86_64 -enable-kvm -cpu Westmere with 320M memory
>
> caused below changes:
>
>
> +-------------------------+------------+------------+
> |                         | 8175435777 | 54cc07a761 |
> +-------------------------+------------+------------+
> | boot_successes          | 102        | 16         |
> | boot_failures           | 0          | 3          |
> | BUG:kernel_test_crashed | 0          | 3          |
> | timestamp.last          | 0          | 54.951425  |
> +-------------------------+------------+------------+
>
>
>
> [   19.206454] VFS: Warning: trinity-c0 using old stat() call. Recompile your binary.
>
> Elapsed time: 70
> BUG: kernel test crashed

What application generated the line "BUG: kernel test crashed."
What flavor of crash was this?

Given the last boot test failure that was reported to me was about 10
commits after the problem commit I unfortunately can't take it at face
value that the appropriate commit has been pinpointed.

If you could give me enough information to dig into this that would
be great.  Otherwise I am going to have to proceed forward on the basis
that this is a testing robot failure, and that the people who maintain
the testing robot don't care enough to look after it.

Eric

Re: [LKP] More information please. Re: [fs] 54cc07a761: BUG: kernel test crashed

[Fengguang Wu]

Hi Eric,

Sorry for the delay!

On Mon, Jul 25, 2016 at 01:57:00PM -0500, Eric W. Biederman wrote:
>kernel test robot <xiaolong.ye@intel.com> writes:
>
>> FYI, we noticed the following commit:
>>
>> https://git.kernel.org/pub/scm/linux/kernel/git/ebiederm/user-namespace.git for-testing
>> commit 54cc07a761deb38318aca64ddf07fc45157c85e0 ("fs: Call d_automount with the filesystems creds")
>>
>> in testcase: boot
>>
>> on test machine: 1 threads qemu-system-x86_64 -enable-kvm -cpu Westmere with 320M memory
>>
>> caused below changes:
>>
>>
>> +-------------------------+------------+------------+
>> |                         | 8175435777 | 54cc07a761 |
>> +-------------------------+------------+------------+
>> | boot_successes          | 102        | 16         |
>> | boot_failures           | 0          | 3          |
>> | BUG:kernel_test_crashed | 0          | 3          |
>> | timestamp.last          | 0          | 54.951425  |
>> +-------------------------+------------+------------+
>>
>>
>>
>> [   19.206454] VFS: Warning: trinity-c0 using old stat() call. Recompile your binary.
>>
>> Elapsed time: 70
>> BUG: kernel test crashed
>
>What application generated the line "BUG: kernel test crashed."
>What flavor of crash was this?

It's a simple boot test with a quick trinity run. So there will be
some randomness in this test.

The "BUG: kernel test crashed" means the VM reboots by itself while
the trinity test is running. If the error message is "BUG: kernel boot
crashed" it'd mean VM abnormally reboots before any test is launched.

>Given the last boot test failure that was reported to me was about 10
>commits after the problem commit I unfortunately can't take it at face
>value that the appropriate commit has been pinpointed.
>
>If you could give me enough information to dig into this that would
>be great.  Otherwise I am going to have to proceed forward on the basis
>that this is a testing robot failure, and that the people who maintain
>the testing robot don't care enough to look after it.

I queued more tests in various KVM instances and find the kernel test
crashes can also happen in the parent commit. So it looks like a false
report. Sorry for the noise!

81754357770ebd90  aeaa4a79ff6a5ed912b7362f20
----------------  --------------------------
       fail:runs  %reproduction    fail:runs
           |             |             |
          5:100          0%           5:100   dmesg.BUG:kernel_test_crashed
           :100          1%           1:100   dmesg.Mem-Info
           :100          1%           1:100   dmesg.invoked_oom-killer:gfp_mask=0x
 
Regards,
Fengguang

Re: [LKP] More information please. Re: [fs] 54cc07a761: BUG: kernel test crashed

[Eric W. Biederman]

Fengguang Wu <fengguang.wu@intel.com> writes:
> On Mon, Jul 25, 2016 at 01:57:00PM -0500, Eric W. Biederman wrote:
>>kernel test robot <xiaolong.ye@intel.com> writes:
[snip]
>>>
>>> [   19.206454] VFS: Warning: trinity-c0 using old stat() call. Recompile your binary.
>>>
>>> Elapsed time: 70
>>> BUG: kernel test crashed
>>
>>What application generated the line "BUG: kernel test crashed."
>>What flavor of crash was this?
>
> It's a simple boot test with a quick trinity run. So there will be
> some randomness in this test.
>
> The "BUG: kernel test crashed" means the VM reboots by itself while
> the trinity test is running. If the error message is "BUG: kernel boot
> crashed" it'd mean VM abnormally reboots before any test is launched.

Is it possible to include a url pointing to a page of documentation
holding this information in your emails or alternatively a url pointing
to some source code.  Just so other people don't have to ask you this
question.

>>Given the last boot test failure that was reported to me was about 10
>>commits after the problem commit I unfortunately can't take it at face
>>value that the appropriate commit has been pinpointed.
>>
>>If you could give me enough information to dig into this that would
>>be great.  Otherwise I am going to have to proceed forward on the basis
>>that this is a testing robot failure, and that the people who maintain
>>the testing robot don't care enough to look after it.
>
> I queued more tests in various KVM instances and find the kernel test
> crashes can also happen in the parent commit. So it looks like a false
> report. Sorry for the noise!
>
> 81754357770ebd90  aeaa4a79ff6a5ed912b7362f20
> ----------------  --------------------------
>       fail:runs  %reproduction    fail:runs
>           |             |             |
>          5:100          0%           5:100   dmesg.BUG:kernel_test_crashed
>           :100          1%           1:100   dmesg.Mem-Info
>           :100          1%           1:100   dmesg.invoked_oom-killer:gfp_mask=0x

Thank you for verifying this.

Eric

Re: [LKP] More information please. Re: [fs] 54cc07a761: BUG: kernel test crashed

[Fengguang Wu]

On Tue, Jul 26, 2016 at 09:52:40AM -0500, Eric W. Biederman wrote:
>Fengguang Wu <fengguang.wu@intel.com> writes:
>> On Mon, Jul 25, 2016 at 01:57:00PM -0500, Eric W. Biederman wrote:
>>>kernel test robot <xiaolong.ye@intel.com> writes:
>[snip]
>>>>
>>>> [   19.206454] VFS: Warning: trinity-c0 using old stat() call. Recompile your binary.
>>>>
>>>> Elapsed time: 70
>>>> BUG: kernel test crashed
>>>
>>>What application generated the line "BUG: kernel test crashed."
>>>What flavor of crash was this?
>>
>> It's a simple boot test with a quick trinity run. So there will be
>> some randomness in this test.
>>
>> The "BUG: kernel test crashed" means the VM reboots by itself while
>> the trinity test is running. If the error message is "BUG: kernel boot
>> crashed" it'd mean VM abnormally reboots before any test is launched.
>
>Is it possible to include a url pointing to a page of documentation
>holding this information in your emails or alternatively a url pointing
>to some source code.  Just so other people don't have to ask you this
>question.

Yes that's the right directions to follow. We'll make the reports more
understandable and the test/bisects more reliable.

In particular, I suspect this false report might be related to QEMU
watchdog. The wild guess is, if trinity touches the watchdog device by
accident, it may result in the VM reset w/o any symptom.

>>>Given the last boot test failure that was reported to me was about 10
>>>commits after the problem commit I unfortunately can't take it at face
>>>value that the appropriate commit has been pinpointed.
>>>
>>>If you could give me enough information to dig into this that would
>>>be great.  Otherwise I am going to have to proceed forward on the basis
>>>that this is a testing robot failure, and that the people who maintain
>>>the testing robot don't care enough to look after it.
>>
>> I queued more tests in various KVM instances and find the kernel test
>> crashes can also happen in the parent commit. So it looks like a false
>> report. Sorry for the noise!
>>
>> 81754357770ebd90  aeaa4a79ff6a5ed912b7362f20
>> ----------------  --------------------------
>>       fail:runs  %reproduction    fail:runs
>>           |             |             |
>>          5:100          0%           5:100   dmesg.BUG:kernel_test_crashed
>>           :100          1%           1:100   dmesg.Mem-Info
>>           :100          1%           1:100   dmesg.invoked_oom-killer:gfp_mask=0x
>
>Thank you for verifying this.

You are welcome!

Thanks,
Fengguang

Re: [LKP] More information please. Re: [fs] 54cc07a761: BUG: kernel test crashed

[Eric W. Biederman]

Fengguang Wu <fengguang.wu@intel.com> writes:

> On Tue, Jul 26, 2016 at 09:52:40AM -0500, Eric W. Biederman wrote:
>>Fengguang Wu <fengguang.wu@intel.com> writes:
>>> On Mon, Jul 25, 2016 at 01:57:00PM -0500, Eric W. Biederman wrote:
>>>>kernel test robot <xiaolong.ye@intel.com> writes:
>>[snip]
>>>>>
>>>>> [   19.206454] VFS: Warning: trinity-c0 using old stat() call. Recompile your binary.
>>>>>
>>>>> Elapsed time: 70
>>>>> BUG: kernel test crashed
>>>>
>>>>What application generated the line "BUG: kernel test crashed."
>>>>What flavor of crash was this?
>>>
>>> It's a simple boot test with a quick trinity run. So there will be
>>> some randomness in this test.
>>>
>>> The "BUG: kernel test crashed" means the VM reboots by itself while
>>> the trinity test is running. If the error message is "BUG: kernel boot
>>> crashed" it'd mean VM abnormally reboots before any test is launched.
>>
>>Is it possible to include a url pointing to a page of documentation
>>holding this information in your emails or alternatively a url pointing
>>to some source code.  Just so other people don't have to ask you this
>>question.
>
> Yes that's the right directions to follow. We'll make the reports more
> understandable and the test/bisects more reliable.

Thanks.  Does trinity have a random seed it can export/import to rerun
the same tests?  I ask because there was a failure these tests caught
that if the right kernel options was enabled was 100% reliable and it
blamed a commit 10 patches down from the indicated commit.  The problem
being 100% reproducible it wasn't an issue that the indicated commit
was wrong.  But a 100% reliable failure being misattributed suggest
a way attribution could become more reliable.

> In particular, I suspect this false report might be related to QEMU
> watchdog. The wild guess is, if trinity touches the watchdog device by
> accident, it may result in the VM reset w/o any symptom.

Interesting.  I hope it is the watchdog.  I know some qemu versions +
some kernel versions have race conditions that are observable during
boot.  I don't know if those happen in your test harness but it may be
worth a look.  I tend to get grumpy when I see those and work on
stabalizing a magic kernel config that likes qemu, but I keep finding
issues when I try other peoples configurations for reproducing problems
like this one.

Eric

Re: [LKP] More information please. Re: [fs] 54cc07a761: BUG: kernel test crashed

[Dave Jones]

On Tue, Jul 26, 2016 at 11:13:44PM +0800, Fengguang Wu wrote:
 
 > >> The "BUG: kernel test crashed" means the VM reboots by itself while
 > >> the trinity test is running. If the error message is "BUG: kernel boot
 > >> crashed" it'd mean VM abnormally reboots before any test is launched.
 > >
 > >Is it possible to include a url pointing to a page of documentation
 > >holding this information in your emails or alternatively a url pointing
 > >to some source code.  Just so other people don't have to ask you this
 > >question.
 > 
 > Yes that's the right directions to follow. We'll make the reports more
 > understandable and the test/bisects more reliable.
 > 
 > In particular, I suspect this false report might be related to QEMU
 > watchdog. The wild guess is, if trinity touches the watchdog device by
 > accident, it may result in the VM reset w/o any symptom.
 
See ignore_files() in pathnames.c
Adding an entry to the blacklist there is easy enough to prove/disprove this.

	Dave

Re: [LKP] More information please. Re: [fs] 54cc07a761: BUG: kernel test crashed

[Dave Jones]

On Tue, Jul 26, 2016 at 02:50:58PM -0500, Eric W. Biederman wrote:

 > > Yes that's the right directions to follow. We'll make the reports more
 > > understandable and the test/bisects more reliable.
 > 
 > Thanks.  Does trinity have a random seed it can export/import to rerun
 > the same tests?  I ask because there was a failure these tests caught
 > that if the right kernel options was enabled was 100% reliable and it
 > blamed a commit 10 patches down from the indicated commit.

It does log the random seed on startup, and can replay it with the -s option

There is some variance if you were to do two runs with the same seed back
to back, because on startup, it walks /proc & /sys, and they'd see different things
so for eg "read() from fd 100" might mean something entirely different.

But as the testbot runs a pretty minimal userspace, only runs trinity once,
and really early in boot, this point might not matter.

	Dave