lkml.org 
[lkml]   [2020]   [Feb]   [17]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Date
From
SubjectRe: [tracing] 1b6c0739c6: BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c
Hi,

I'm investigating this issue. This seems that my fix is not enough, there seems some other issues still in the test module.

Thank you,

On Mon, 17 Feb 2020 08:34:44 +0800
kernel test robot <lkp@intel.com> wrote:

> FYI, we noticed the following commit (built with gcc-7):
>
> commit: 1b6c0739c611f3b5373e27571cc93064c423731d ("tracing: Skip software disabled event at __synth_event_trace_end()")
> https://github.com/0day-ci/linux/commits/Masami-Hiramatsu/tracing-Skip-software-disabled-event-at-__synth_event_trace_end/20200215-100354
>
> in testcase: trinity
> with following parameters:
>
> runtime: 300s
>
> test-description: Trinity is a linux system call fuzz tester.
> test-url: http://codemonkey.org.uk/projects/trinity/
>
>
> on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 8G
>
> caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
>
>
> +-----------------------------------------------------------------------------+------------+------------+
> | | 7276531d40 | 1b6c0739c6 |
> +-----------------------------------------------------------------------------+------------+------------+
> | boot_successes | 22 | 0 |
> | boot_failures | 0 | 22 |
> | BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c | 0 | 6 |
> | initcall_synth_event_gen_test_init_returned_with_preemption_imbalance | 0 | 22 |
> | WARNING:at_init/main.c:#do_one_initcall | 0 | 22 |
> | RIP:do_one_initcall | 0 | 22 |
> | BUG:sleeping_function_called_from_invalid_context_at_mm/page_alloc.c | 0 | 16 |
> +-----------------------------------------------------------------------------+------------+------------+
>
>
> If you fix the issue, kindly add following tag
> Reported-by: kernel test robot <lkp@intel.com>
>
>
> [ 6.998544] BUG: sleeping function called from invalid context at mm/page_alloc.c:4695
> [ 7.000227] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 1, name: swapper/0
> [ 7.001487] no locks held by swapper/0/1.
> [ 7.002172] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.5.0-rc6-00098-g1b6c0739c611f #2
> [ 7.003522] Call Trace:
> [ 7.003962] dump_stack+0x57/0x75
> [ 7.004179] ___might_sleep+0x111/0x120
> [ 7.004179] __might_sleep+0x68/0x70
> [ 7.004179] __alloc_pages_nodemask+0xe9/0x250
> [ 7.004179] ? test_empty_synth_event+0x1f/0x222
> [ 7.004179] slob_new_pages+0x13/0xa0
> [ 7.004179] slob_alloc+0x2b8/0x2e0
> [ 7.004179] ? test_empty_synth_event+0x1f/0x222
> [ 7.004179] __kmalloc+0x1cd/0x1f0
> [ 7.004179] ? test_empty_synth_event+0x222/0x222
> [ 7.004179] ? do_early_param+0x92/0x92
> [ 7.004179] test_empty_synth_event+0x1f/0x222
> [ 7.004179] ? print_synth_event+0x2c0/0x2c0
> [ 7.004179] ? test_empty_synth_event+0x222/0x222
> [ 7.004179] synth_event_gen_test_init+0x1d/0x3bd
> [ 7.004179] ? init_tracepoints+0x28/0x28
> [ 7.004179] ? do_early_param+0x92/0x92
> [ 7.004179] ? proc_create_data+0x3b/0x50
> [ 7.004179] ? proc_create+0xf/0x20
> [ 7.004179] do_one_initcall+0xae/0x210
> [ 7.004179] kernel_init_freeable+0x1e4/0x25c
> [ 7.004179] ? rest_init+0x140/0x140
> [ 7.004179] kernel_init+0x9/0x100
> [ 7.004179] ret_from_fork+0x35/0x40
> [ 7.026429] ------------[ cut here ]------------
> [ 7.027238] initcall synth_event_gen_test_init+0x0/0x3bd returned with preemption imbalance
> [ 7.028721] WARNING: CPU: 0 PID: 1 at init/main.c:1159 do_one_initcall+0x1c4/0x210
> [ 7.030508] Modules linked in:
> [ 7.031114] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G W 5.5.0-rc6-00098-g1b6c0739c611f #2
> [ 7.032901] RIP: 0010:do_one_initcall+0x1c4/0x210
> [ 7.033805] Code: 40 00 00 00 48 c7 c6 a6 7a e2 81 e8 86 91 70 00 fb 80 7d a0 00 74 1d 48 8d 55 a0 4c 89 e6 48 c7 c7 b0 7e e2 81 e8 fc b2 09 00 <0f> 0b eb 06 41 bd ff ff ff ff 48 83 c4 40 44 89 e8 5b 41 5c 41 5d
> [ 7.035098] RSP: 0000:ffffc90000013e98 EFLAGS: 00010292
> [ 7.035098] RAX: 0000000000000050 RBX: 0000000000000000 RCX: 0000000000000000
> [ 7.035098] RDX: 0000000000000000 RSI: 00000001a2f14e6c RDI: ffffffff82054880
> [ 7.035098] RBP: ffffc90000013ef8 R08: 0000000000000001 R09: 0000000000000001
> [ 7.035098] R10: 0000000000000010 R11: 0000000000000000 R12: ffffffff824b1bab
> [ 7.035098] R13: 0000000000000000 R14: 0000000000000007 R15: ffffffff8248f6fd
> [ 7.035098] FS: 0000000000000000(0000) GS:ffff888236a00000(0000) knlGS:0000000000000000
> [ 7.035098] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 7.035098] CR2: 0000000000000000 CR3: 0000000002012000 CR4: 00000000000406f0
> [ 7.035098] Call Trace:
> [ 7.035098] kernel_init_freeable+0x1e4/0x25c
> [ 7.035098] ? rest_init+0x140/0x140
> [ 7.035098] kernel_init+0x9/0x100
> [ 7.035098] ret_from_fork+0x35/0x40
> [ 7.035098] ---[ end trace 0953bc968f723b18 ]---
>
>
> To reproduce:
>
> # build kernel
> cd linux
> cp config-5.5.0-rc6-00098-g1b6c0739c611f .config
> make HOSTCC=gcc-7 CC=gcc-7 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage
>
> git clone https://github.com/intel/lkp-tests.git
> cd lkp-tests
> bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
>
>
>
> Thanks,
> lkp
>


--
Masami Hiramatsu <mhiramat@kernel.org>

\
 
 \ /
  Last update: 2020-02-17 09:47    [W:0.443 / U:0.144 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site