[kernel] 92114220fe: BUG:unable_to_handle_kernel
by kernel test robot
FYI, we noticed the following commit (built with gcc-6):
commit: 92114220fe6a374172e99261b6451c515d29c8dc ("[PATCH] kernel: prevent submission of creds with higher privileges inside container")
url: https://github.com/0day-ci/linux/commits/My-Name/kernel-prevent-submissio...
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 -m 256M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------+-----------+------------+
| | v4.19-rc3 | 92114220fe |
+------------------------------------------+-----------+------------+
| boot_successes | 8 | 0 |
| boot_failures | 0 | 6 |
| BUG:unable_to_handle_kernel | 0 | 6 |
| Oops:#[##] | 0 | 6 |
| RIP:commit_creds | 0 | 6 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 6 |
+------------------------------------------+-----------+------------+
[ 53.586547] BUG: unable to handle kernel NULL pointer dereference at 00000000000006c0
[ 53.588054] PGD 0 P4D 0
[ 53.588564] Oops: 0000 [#1] PTI
[ 53.589180] CPU: 0 PID: 1 Comm: init Not tainted 4.19.0-rc3-00001-g9211422 #1
[ 53.590544] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 53.592139] RIP: 0010:commit_creds+0x51/0x410
[ 53.592988] Code: 08 81 ba b0 01 00 00 fe ff ff ef 74 11 8b 43 04 39 47 04 0f 83 9c 00 00 00 e9 c2 03 00 00 48 8b 50 10 48 83 05 67 82 5a 02 01 <81> ba c0 06 00 00 ff ff ff ef 75 d7 48 8b 50 18 48 83 05 57 82 5a
[ 53.596525] RSP: 0000:ffffc9000000bd10 EFLAGS: 00010202
[ 53.597526] RAX: ffffffff82ca3060 RBX: ffff88000f02eb40 RCX: ffff88000f0399c8
[ 53.598883] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff88000b2a53c0
[ 53.600235] RBP: ffff88000bd66800 R08: ffff88000f030740 R09: 00000000008fb60c
[ 53.601587] R10: 00000000e0098d8b R11: 0000000010c12b46 R12: ffff88000f030040
[ 53.602936] R13: ffffc90000008000 R14: ffff88000cd07500 R15: 0000000000000001
[ 53.604285] FS: 0000000000000000(0000) GS:ffffffff82c5b000(0000) knlGS:0000000000000000
[ 53.605813] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 53.606906] CR2: 00000000000006c0 CR3: 000000000c6f6000 CR4: 00000000000406b0
[ 53.608264] Call Trace:
[ 53.608762] install_exec_creds+0x25/0xa0
[ 53.609544] load_elf_binary+0x544/0x1e72
[ 53.610324] ? __lock_acquire+0xdbb/0x1030
[ 53.611234] ? find_held_lock+0x35/0xd0
[ 53.611982] ? __lock_acquire+0xdbb/0x1030
[ 53.612891] ? find_held_lock+0x35/0xd0
[ 53.613639] ? search_binary_handler+0x83/0x180
[ 53.614512] search_binary_handler+0x98/0x180
[ 53.615356] load_script+0x348/0x370
[ 53.616058] search_binary_handler+0x98/0x180
[ 53.616906] __do_execve_file+0x7d3/0xaa0
[ 53.617804] do_execve+0x24/0x30
[ 53.618439] run_init_process+0x50/0x60
[ 53.619184] ? rest_init+0x1a0/0x1a0
[ 53.619885] kernel_init+0xca/0x1e0
[ 53.620573] ret_from_fork+0x35/0x40
[ 53.621264] CR2: 00000000000006c0
[ 53.621969] ---[ end trace 3c2bcf9b443a9ddd ]---
To reproduce:
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
3 years
[vfs] fd0002870b: BUG:KASAN:null-ptr-deref_in_n
by kernel test robot
FYI, we noticed the following commit (built with gcc-6):
commit: fd0002870b453c58d0d8c195954f5049bc6675fb ("vfs: Implement a filesystem superblock creation/configuration context")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap -smp 2 -m 1G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------+------------+------------+
| | bae551929c | fd0002870b |
+------------------------------------------+------------+------------+
| boot_successes | 6 | 2 |
| boot_failures | 0 | 11 |
| BUG:KASAN:null-ptr-deref_in_n | 0 | 11 |
| BUG:unable_to_handle_kernel | 0 | 11 |
| Oops:#[##] | 0 | 11 |
| RIP:nfs_fs_mount | 0 | 11 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 11 |
+------------------------------------------+------------+------------+
[ 18.557980] BUG: KASAN: null-ptr-deref in nfs_fs_mount+0x901/0x1220
[ 18.559674] Read of size 1 at addr 0000000000000000 by task mount.nfs/357
[ 18.561456]
[ 18.562063] CPU: 0 PID: 357 Comm: mount.nfs Not tainted 4.19.0-rc1-00104-gfd00028 #1
[ 18.564199] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 18.566478] Call Trace:
[ 18.567308] kasan_report+0x107/0x330
[ 18.568403] nfs_fs_mount+0x901/0x1220
[ 18.569523] ? kmem_cache_free+0x70/0x170
[ 18.570710] ? nfs_compare_super+0x440/0x440
[ 18.571944] ? nd_jump_link+0xb0/0xb0
[ 18.573039] ? ksys_mount+0x5a/0xc0
[ 18.574106] ? strcmp+0x30/0x50
[ 18.575083] ? nfs_clone_super+0x150/0x150
[ 18.576273] ? nfs_remount+0x890/0x890
[ 18.577395] ? vfs_parse_fs_string+0xad/0xe0
[ 18.578629] ? nfs_compare_super+0x440/0x440
[ 18.579895] ? legacy_get_tree+0x83/0x180
[ 18.581069] legacy_get_tree+0x83/0x180
[ 18.582204] vfs_get_tree+0xaf/0x250
[ 18.583272] do_mount+0x39b/0xfe0
[ 18.584282] ? __might_sleep+0x2e/0xd0
[ 18.585394] ? __might_sleep+0x2e/0xd0
[ 18.586507] ? copy_mount_string+0x20/0x20
[ 18.587697] ? copy_mount_options+0x3a/0x1c0
[ 18.588842] ? copy_mount_options+0xf1/0x1c0
[ 18.589936] ksys_mount+0x79/0xc0
[ 18.590831] __x64_sys_mount+0x5d/0x70
[ 18.591819] do_syscall_64+0xac/0x3d0
[ 18.593009] ? syscall_return_slowpath+0xb0/0xb0
[ 18.594185] ? mm_fault_error+0x1c0/0x1c0
[ 18.595256] ? __put_user_4+0x1b/0x30
[ 18.596222] ? async_page_fault+0x8/0x30
[ 18.597251] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 18.598505] RIP: 0033:0x7fd79e7f424a
[ 18.599463] Code: 48 8b 0d 51 fc 2a 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 1e fc 2a 00 f7 d8 64 89 01 48
[ 18.606261] RSP: 002b:00007ffe34069b58 EFLAGS: 00000202 ORIG_RAX: 00000000000000a5
[ 18.608156] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fd79e7f424a
[ 18.609829] RDX: 0000558512e8cf70 RSI: 0000558512e8cf50 RDI: 0000558512e8b210
[ 18.611506] RBP: 00007ffe34069d50 R08: 0000558512e98320 R09: 0000000000000060
[ 18.613359] R10: 0000000000000000 R11: 0000000000000202 R12: 00007fd79f138410
[ 18.615038] R13: 00007ffe34069d50 R14: 00007ffe34069c50 R15: 0000558512e98300
[ 18.616716] ==================================================================
[ 18.618528] Disabling lock debugging due to kernel taint
[ 18.762009] BUG: unable to handle kernel NULL pointer dereference at 0000000000000000
[ 18.764184] PGD 0 P4D 0
[ 18.765016] Oops: 0000 [#1] PREEMPT KASAN PTI
[ 18.766279] CPU: 0 PID: 357 Comm: mount.nfs Tainted: G B 4.19.0-rc1-00104-gfd00028 #1
[ 18.768705] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 18.770938] RIP: 0010:nfs_fs_mount+0x901/0x1220
[ 18.772208] Code: 02 74 06 66 83 f8 0a 75 19 48 8d bb 2a 01 00 00 66 41 c1 c4 08 e8 df 33 f1 ff 66 44 89 a3 2a 01 00 00 4c 89 ef e8 bf 32 f1 ff <41> 80 7d 00 5b 0f 84 4a 08 00 00 be 3a 00 00 00 4c 89 ef e8 b7 9a
[ 18.776851] RSP: 0000:ffff88001ff1fb70 EFLAGS: 00010292
[ 18.778318] RAX: ffff88001ed45c00 RBX: ffff880017e19b80 RCX: 0000000000000000
[ 18.780200] RDX: 0000000000000001 RSI: dffffc0000000000 RDI: ffffffff82cdcf80
[ 18.782055] RBP: ffff88001ff1fc90 R08: fffffbfff0495731 R09: fffffbfff0495730
[ 18.783938] R10: 0000000000000003 R11: fffffbfff0495731 R12: 0000000000000000
[ 18.785811] R13: 0000000000000000 R14: 0000000000001000 R15: ffff880017e19ca8
[ 18.787709] FS: 00007fd79f138480(0000) GS:ffffffff82465000(0000) knlGS:0000000000000000
[ 18.789910] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 18.791455] CR2: 0000000000000000 CR3: 000000003fb6a003 CR4: 00000000000606f0
[ 18.793339] Call Trace:
[ 18.794147] ? kmem_cache_free+0x70/0x170
[ 18.795296] ? nfs_compare_super+0x440/0x440
[ 18.796504] ? nd_jump_link+0xb0/0xb0
[ 18.797603] ? ksys_mount+0x5a/0xc0
[ 18.798643] ? strcmp+0x30/0x50
[ 18.799610] ? nfs_clone_super+0x150/0x150
[ 18.800813] ? nfs_remount+0x890/0x890
[ 18.801945] ? vfs_parse_fs_string+0xad/0xe0
[ 18.803155] ? nfs_compare_super+0x440/0x440
[ 18.804383] ? legacy_get_tree+0x83/0x180
[ 18.805558] legacy_get_tree+0x83/0x180
[ 18.806690] vfs_get_tree+0xaf/0x250
[ 18.807765] do_mount+0x39b/0xfe0
[ 18.808776] ? __might_sleep+0x2e/0xd0
[ 18.809792] ? __might_sleep+0x2e/0xd0
[ 18.810887] ? copy_mount_string+0x20/0x20
[ 18.812072] ? copy_mount_options+0x3a/0x1c0
[ 18.813310] ? copy_mount_options+0xf1/0x1c0
[ 18.814555] ksys_mount+0x79/0xc0
[ 18.815572] __x64_sys_mount+0x5d/0x70
[ 18.816683] do_syscall_64+0xac/0x3d0
[ 18.817785] ? syscall_return_slowpath+0xb0/0xb0
[ 18.819175] ? mm_fault_error+0x1c0/0x1c0
[ 18.820350] ? __put_user_4+0x1b/0x30
[ 18.821455] ? async_page_fault+0x8/0x30
[ 18.822622] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 18.824024] RIP: 0033:0x7fd79e7f424a
[ 18.825087] Code: 48 8b 0d 51 fc 2a 00 f7 d8 64 89 01 48 83 c8 ff c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 44 00 00 49 89 ca b8 a5 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 1e fc 2a 00 f7 d8 64 89 01 48
[ 18.829774] RSP: 002b:00007ffe34069b58 EFLAGS: 00000202 ORIG_RAX: 00000000000000a5
[ 18.831873] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007fd79e7f424a
[ 18.833764] RDX: 0000558512e8cf70 RSI: 0000558512e8cf50 RDI: 0000558512e8b210
[ 18.835657] RBP: 00007ffe34069d50 R08: 0000558512e98320 R09: 0000000000000060
[ 18.837543] R10: 0000000000000000 R11: 0000000000000202 R12: 00007fd79f138410
[ 18.839426] R13: 00007ffe34069d50 R14: 00007ffe34069c50 R15: 0000558512e98300
[ 18.841309] Modules linked in: crc32_pclmul ghash_clmulni_intel aesni_intel crypto_simd input_leds led_class floppy cmdlinepart
[ 18.844315] CR2: 0000000000000000
[ 19.028656] ---[ end trace df17e7a878a94ae1 ]---
To reproduce:
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
3 years
[kernfs, sysfs, cgroup, intel_rdt] a8c7fe83d1: BUG:kernel_hang_in_test_stage
by kernel test robot
FYI, we noticed the following commit (built with gcc-6):
commit: a8c7fe83d17109b77c7b27a23140e76d3753fa6a ("kernfs, sysfs, cgroup, intel_rdt: Support fs_context")
https://git.kernel.org/cgit/linux/kernel/git/dhowells/linux-fs.git btrfs-mount-api
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 Haswell,+smep,+smap -smp 2 -m 2G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------------------------+------------+------------+
| | 88ed9083f5 | a8c7fe83d1 |
+------------------------------------------------------------------+------------+------------+
| boot_successes | 2 | 0 |
| boot_failures | 10 | 10 |
| BUG:KASAN:null-ptr-deref_in_n | 10 | |
| BUG:unable_to_handle_kernel | 10 | |
| Oops:#[##] | 10 | |
| RIP:nfs_fs_mount | 10 | |
| Kernel_panic-not_syncing:Fatal_exception | 10 | |
| BUG:kernel_hang_in_test_stage | 0 | 8 |
| invoked_oom-killer:gfp_mask=0x | 0 | 2 |
| Mem-Info | 0 | 2 |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 0 | 2 |
+------------------------------------------------------------------+------------+------------+
[ 17.521153] random: get_random_bytes called from flow_hash_from_keys+0x3e9/0x480 with crng_init=0
[ 17.526197] random: get_random_bytes called from addrconf_dad_kick+0xf7/0x1a0 with crng_init=0
[ 55.227136] random: get_random_bytes called from __prandom_timer+0x57/0xc0 with crng_init=0
[ 442.854487] random: fast init done
[ 880.187591] random: crng init done
BUG: kernel hang in test stage
Elapsed time: 2690
#!/bin/bash
To reproduce:
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,
Rong, Chen
3 years
[blkcg] 1d0e59f90b: BUG:unable_to_handle_kernel
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 1d0e59f90bff75f1b2620ac298f12dda2a84b5e8 ("[PATCH 10/12] blkcg: cleanup and make blk_get_rl use blkg_lookup_create")
url: https://github.com/0day-ci/linux/commits/Dennis-Zhou/block-always-associa...
base: https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git for-next
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 -m 256M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+----------------+------------+------------+
| | 7fbc5786e4 | 1d0e59f90b |
+----------------+------------+------------+
| boot_successes | 10 | 0 |
+----------------+------------+------------+
[ 4.614577] BUG: unable to handle kernel NULL pointer dereference at 0000000000000028
[ 4.617799] PGD 0 P4D 0
[ 4.617799] Oops: 0000 [#1] SMP PTI
[ 4.617799] CPU: 0 PID: 16 Comm: kworker/u2:1 Not tainted 4.19.0-rc2-00205-g1d0e59f #1
[ 4.617799] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 4.617799] Workqueue: events_unbound async_run_entry_fn
[ 4.617799] RIP: 0010:get_request+0xfe/0x737
[ 4.617799] Code: 48 8d 58 40 e9 aa 00 00 00 e8 08 34 c3 ff 48 85 c0 49 89 c7 75 14 65 48 8b 04 25 80 4d 01 00 48 8b 80 b8 07 00 00 4c 8b 78 10 <48> 81 3c 25 28 00 00 00 00 5a c2 82 74 70 48 8b 85 a8 01 00 00 a8
[ 4.617799] RSP: 0000:ffffc900000ebc28 EFLAGS: 00010046
[ 4.617799] RAX: ffffffff82476e40 RBX: 0000000000600000 RCX: 0000000000000008
[ 4.617799] RDX: ffff88000de2cc00 RSI: 0000000000000020 RDI: ffff88000f90dff0
[ 4.617799] RBP: ffff88000f90dff0 R08: 0000000000600000 R09: 0000000000000000
[ 4.617799] R10: ffff88000f6c9800 R11: ffff88000d4caf7e R12: 0000000000000000
[ 4.617799] R13: 0000000000000000 R14: 0000000000000000 R15: ffffffff82c25a00
[ 4.617799] FS: 0000000000000000(0000) GS:ffff88000e000000(0000) knlGS:0000000000000000
[ 4.617799] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 4.617799] CR2: 0000000000000028 CR3: 000000000240a000 CR4: 00000000000006f0
[ 4.617799] Call Trace:
[ 4.617799] ? wait_woken+0x8b/0x8b
[ 4.617799] blk_get_request+0xd7/0x14f
[ 4.617799] __scsi_execute+0x43/0x17b
[ 4.617799] scsi_probe_and_add_lun+0x23b/0xac2
[ 4.617799] __scsi_add_device+0xd4/0x128
[ 4.617799] ata_scsi_scan_host+0x86/0x173
[ 4.617799] async_run_entry_fn+0x6f/0x12f
[ 4.617799] process_one_work+0x1d5/0x316
[ 4.617799] ? worker_thread+0x24e/0x2d6
[ 4.617799] worker_thread+0x1f2/0x2d6
[ 4.617799] ? rescuer_thread+0x2cf/0x2cf
[ 4.617799] kthread+0x121/0x129
[ 4.617799] ? kthread_park+0x76/0x76
[ 4.617799] ret_from_fork+0x3a/0x50
[ 4.617799] Modules linked in:
[ 4.617799] CR2: 0000000000000028
[ 4.617799] ---[ end trace ad69c92e3fbca4bc ]---
To reproduce:
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
3 years
[blkcg] 22f657e287: general_protection_fault:#[##]
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 22f657e2876612270ad346b7f5ba2493ba434d41 ("[PATCH 12/15] blkcg: cleanup and make blk_get_rl use blkg_lookup_create")
url: https://github.com/0day-ci/linux/commits/Dennis-Zhou/blkcg-ref-count-refa...
base: https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git for-next
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 Haswell,+smep,+smap -smp 2 -m 512M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------------------------+------------+------------+
| | f743a58719 | 22f657e287 |
+------------------------------------------------------------------+------------+------------+
| boot_successes | 3 | 0 |
| boot_failures | 10 | 16 |
| invoked_oom-killer:gfp_mask=0x | 6 | 6 |
| Mem-Info | 6 | 6 |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 6 | 6 |
| IP-Config:Auto-configuration_of_network_failed | 4 | |
| general_protection_fault:#[##] | 0 | 10 |
| RIP:get_request | 0 | 10 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 10 |
+------------------------------------------------------------------+------------+------------+
[ 93.607840] SCSI Media Changer driver v0.25
[ 93.667470] scsi host0: scsi_debug: version 0188 [20180128]
[ 93.667470] dev_size_mb=8, opts=0x0, submit_queues=1, statistics=0
[ 93.756552] kasan: CONFIG_KASAN_INLINE enabled
[ 93.766196] kasan: GPF could be caused by NULL-ptr deref or user memory access
[ 93.766196] general protection fault: 0000 [#1] PREEMPT KASAN
[ 93.766196] CPU: 0 PID: 27 Comm: kworker/u2:1 Not tainted 4.19.0-rc1-00174-g22f657e #1
[ 93.766196] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 93.766196] Workqueue: events_unbound async_run_entry_fn
[ 93.766196] RIP: 0010:get_request+0x11f/0xe24
[ 93.766196] Code: 83 b8 f0 00 00 00 00 74 02 0f 0b e8 6b 78 46 ff 48 8b 44 24 10 48 8d 78 60 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 <80> 3c 02 00 74 05 e8 6d 16 63 ff 48 8b 44 24 10 48 bd 00 00 00 00
[ 93.766196] RSP: 0000:ffff880016c07850 EFLAGS: 00010006
[ 93.766196] RAX: dffffc0000000000 RBX: dffffc0000000000 RCX: 0000000000000008
[ 93.766196] RDX: 000000000000000c RSI: 0000000000000020 RDI: 0000000000000060
[ 93.766196] RBP: ffff88001463b390 R08: 0000000000600000 R09: ffffed0002d80f0f
[ 93.766196] R10: 0000000000000000 R11: ffff880016c07877 R12: 0000000000600000
[ 93.766196] R13: 0000000000000000 R14: 0000000000000020 R15: ffff880014639540
[ 93.766196] FS: 0000000000000000(0000) GS:ffffffff8427e000(0000) knlGS:0000000000000000
[ 93.766196] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 93.766196] CR2: 0000000000000000 CR3: 000000000422c001 CR4: 00000000000206b0
[ 93.766196] Call Trace:
[ 93.766196] ? blk_rq_init+0x27c/0x27c
[ 93.766196] ? blk_exit_rl+0x55/0x55
[ 93.766196] ? __wake_up_common_lock+0x140/0x140
[ 93.766196] ? tracer_preempt_on+0x16/0x25
[ 93.766196] ? preempt_count_sub+0x12d/0x136
[ 93.766196] ? task_unlock+0xa/0x1a
[ 93.766196] ? create_task_io_context+0x2c7/0x2cf
[ 93.766196] blk_get_request+0x14d/0x277
[ 93.766196] __scsi_execute+0x67/0x466
[ 93.766196] scsi_probe_and_add_lun+0x399/0x1d14
[ 93.766196] ? rpm_resume+0xad5/0xb05
[ 93.766196] ? scsi_sanitize_inquiry_string+0x77/0x77
[ 93.766196] ? rpm_put_suppliers+0x10e/0x10e
[ 93.766196] ? scsi_target_reap_ref_release+0x6a/0x6a
[ 93.766196] ? tracer_preempt_on+0x16/0x25
[ 93.766196] ? preempt_count_sub+0x12d/0x136
[ 93.766196] __scsi_scan_target+0x130/0x6af
[ 93.766196] ? __free_pages+0x3c/0x3c
[ 93.766196] ? scsi_probe_and_add_lun+0x1d14/0x1d14
[ 93.766196] ? rpm_resume+0xad5/0xb05
[ 93.766196] ? rpm_put_suppliers+0x10e/0x10e
[ 93.766196] ? __switch_to_asm+0x30/0x60
[ 93.766196] ? ___might_sleep+0xac/0x33e
[ 93.766196] scsi_scan_channel+0xcb/0xe8
[ 93.766196] scsi_scan_host_selected+0x1ca/0x201
[ 93.766196] ? do_scsi_scan_host+0x18a/0x18a
[ 93.766196] do_scan_async+0x3e/0x2ff
[ 93.766196] ? do_scsi_scan_host+0x18a/0x18a
[ 93.766196] async_run_entry_fn+0x1c5/0x33c
[ 93.766196] process_one_work+0x4c0/0x6cd
[ 93.766196] ? preempt_count_sub+0x12d/0x136
[ 93.766196] worker_thread+0x4b3/0x610
[ 93.766196] ? __kthread_parkme+0x9f/0x148
[ 93.766196] kthread+0x2c5/0x2d4
[ 93.766196] ? process_scheduled_works+0x6d/0x6d
[ 93.766196] ? __kthread_cancel_work+0x16b/0x16b
[ 93.766196] ret_from_fork+0x35/0x40
[ 93.766196] ---[ end trace a8869917661828b0 ]---
[ 93.766196] RIP: 0010:get_request+0x11f/0xe24
[ 93.766196] Code: 83 b8 f0 00 00 00 00 74 02 0f 0b e8 6b 78 46 ff 48 8b 44 24 10 48 8d 78 60 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 <80> 3c 02 00 74 05 e8 6d 16 63 ff 48 8b 44 24 10 48 bd 00 00 00 00
[ 93.766196] RSP: 0000:ffff880016c07850 EFLAGS: 00010006
[ 93.766196] RAX: dffffc0000000000 RBX: dffffc0000000000 RCX: 0000000000000008
[ 93.766196] RDX: 000000000000000c RSI: 0000000000000020 RDI: 0000000000000060
[ 93.766196] RBP: ffff88001463b390 R08: 0000000000600000 R09: ffffed0002d80f0f
[ 93.766196] R10: 0000000000000000 R11: ffff880016c07877 R12: 0000000000600000
[ 93.766196] R13: 0000000000000000 R14: 0000000000000020 R15: ffff880014639540
[ 93.766196] FS: 0000000000000000(0000) GS:ffffffff8427e000(0000) knlGS:0000000000000000
[ 93.766196] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 93.766196] CR2: 0000000000000000 CR3: 000000000422c001 CR4: 00000000000206b0
[ 93.766196] Kernel panic - not syncing: Fatal exception
[ 93.766196] Kernel Offset: disabled
Elapsed time: 100
#!/bin/bash
To reproduce:
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,
Rong, Chen
3 years
[x86/pti/64] de87ae2926: will-it-scale.per_thread_ops 3.8% improvement
by kernel test robot
Greeting,
FYI, we noticed a 3.8% improvement of will-it-scale.per_thread_ops due to commit:
commit: de87ae29269664b890e5323ff9649ab7990960cc ("x86/pti/64: Remove the SYSCALL64 entry trampoline")
git://internal_merge_and_test_tree devel-catchup-201808280250
in testcase: will-it-scale
on test machine: 88 threads Intel(R) Xeon(R) CPU E5-2699 v4 @ 2.20GHz with 64G memory
with following parameters:
nr_task: 16
mode: thread
test: futex3
cpufreq_governor: performance
test-description: Will It Scale takes a testcase and runs it from 1 through to n parallel copies to see if the testcase will scale. It builds both a process and threads based test in order to see any differences between the two.
test-url: https://github.com/antonblanchard/will-it-scale
In addition to that, the commit also has significant impact on the following tests:
+------------------+----------------------------------------------------------------------+
| testcase: change | will-it-scale: will-it-scale.per_thread_ops 4.3% improvement |
| test machine | 88 threads Intel(R) Xeon(R) CPU E5-2699 v4 @ 2.20GHz with 64G memory |
| test parameters | cpufreq_governor=performance |
| | mode=thread |
| | nr_task=16 |
| | test=getppid1 |
+------------------+----------------------------------------------------------------------+
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
=========================================================================================
compiler/cpufreq_governor/kconfig/mode/nr_task/rootfs/tbox_group/test/testcase:
gcc-7/performance/x86_64-rhel-7.2/thread/16/debian-x86_64-2018-04-03.cgz/lkp-bdw-ep3d/futex3/will-it-scale
commit:
cba614f88d ("x86/entry/64: Use the TSS sp2 slot for rsp_scratch")
de87ae2926 ("x86/pti/64: Remove the SYSCALL64 entry trampoline")
cba614f88dfdeadd de87ae29269664b890e5323ff9
---------------- --------------------------
%stddev %change %stddev
\ | \
3518673 +3.8% 3650732 will-it-scale.per_thread_ops
3182 -2.2% 3112 will-it-scale.time.system_time
1633 +4.3% 1703 will-it-scale.time.user_time
56298775 +3.8% 58411722 will-it-scale.workload
4744393 ±120% -71.5% 1351494 ± 2% cpuidle.C1.time
2328850 ± 6% +10.4% 2570720 ± 7% softirqs.TIMER
1717 ± 13% +29.9% 2231 ± 4% numa-meminfo.node0.PageTables
15164 ± 18% -62.4% 5695 ± 86% numa-meminfo.node0.Shmem
2576 ± 9% -20.8% 2041 ± 4% numa-meminfo.node1.PageTables
60960 ± 24% -36.5% 38712 ± 19% numa-numastat.node0.local_node
62186 ± 23% -31.4% 42639 ± 16% numa-numastat.node0.numa_hit
1226 ± 57% +220.2% 3926 ± 20% numa-numastat.node0.other_node
3544 ± 20% -76.3% 840.00 ± 95% numa-numastat.node1.other_node
429.25 ± 13% +29.9% 557.50 ± 4% numa-vmstat.node0.nr_page_table_pages
3794 ± 18% -62.5% 1423 ± 86% numa-vmstat.node0.nr_shmem
1373 ± 50% +194.5% 4044 ± 20% numa-vmstat.node0.numa_other
643.25 ± 9% -20.6% 510.75 ± 4% numa-vmstat.node1.nr_page_table_pages
650501 +2.2% 664689 proc-vmstat.numa_hit
645729 +2.2% 659920 proc-vmstat.numa_local
38.50 ± 81% +11564.9% 4491 ± 55% proc-vmstat.numa_pages_migrated
2461 ± 66% +622.7% 17786 ± 66% proc-vmstat.numa_pte_updates
699026 +2.3% 715240 proc-vmstat.pgalloc_normal
783179 +1.6% 795471 proc-vmstat.pgfault
683943 +1.9% 697109 proc-vmstat.pgfree
38.50 ± 81% +11564.9% 4491 ± 55% proc-vmstat.pgmigrate_success
23.57 ± 3% -23.6 0.00 perf-profile.calltrace.cycles-pp.__entry_trampoline_start
0.00 +25.7 25.66 ± 4% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64
23.68 ± 3% -23.7 0.00 perf-profile.children.cycles-pp.__entry_trampoline_start
0.00 +1.1 1.14 ± 6% perf-profile.children.cycles-pp.__x86_indirect_thunk_rax
0.00 +25.7 25.69 ± 4% perf-profile.children.cycles-pp.entry_SYSCALL_64
23.68 ± 3% -23.7 0.00 perf-profile.self.cycles-pp.__entry_trampoline_start
4.62 ± 6% -1.7 2.95 ± 5% perf-profile.self.cycles-pp.do_syscall_64
2.49 ± 5% -0.3 2.23 ± 5% perf-profile.self.cycles-pp.entry_SYSCALL_64_after_hwframe
0.00 +1.1 1.07 ± 5% perf-profile.self.cycles-pp.__x86_indirect_thunk_rax
0.00 +25.7 25.69 ± 4% perf-profile.self.cycles-pp.entry_SYSCALL_64
293.92 ± 22% -27.7% 212.58 ± 6% sched_debug.cfs_rq:/.load_avg.max
81.81 ± 8% -14.8% 69.67 ± 15% sched_debug.cfs_rq:/.load_avg.stddev
10489 ± 4% +16.9% 12261 ± 6% sched_debug.cfs_rq:/.min_vruntime.min
3.27 ± 16% -74.0% 0.85 ±101% sched_debug.cfs_rq:/.removed.util_avg.avg
69.08 ± 24% -72.9% 18.75 ±100% sched_debug.cfs_rq:/.removed.util_avg.max
14.37 ± 19% -73.8% 3.76 ±100% sched_debug.cfs_rq:/.removed.util_avg.stddev
169390 ± 15% +41.4% 239515 ± 19% sched_debug.cpu.avg_idle.min
2349 ± 21% -29.7% 1651 ± 18% sched_debug.cpu.nr_load_updates.stddev
62893 ± 28% -30.1% 43970 ± 14% sched_debug.cpu.sched_count.max
14764 ± 17% -17.6% 12171 ± 10% sched_debug.cpu.sched_count.stddev
279.25 ± 6% -18.2% 228.54 ± 8% sched_debug.cpu.ttwu_count.min
4.42 -1.3 3.12 perf-stat.branch-miss-rate%
5.174e+10 -29.9% 3.624e+10 perf-stat.branch-misses
33184723 ± 4% +15.1% 38191250 ± 12% perf-stat.cache-misses
8.231e+08 +7.9% 8.883e+08 ± 4% perf-stat.cache-references
1.83 -2.2% 1.79 perf-stat.cpi
2.071e+12 +2.1% 2.114e+12 perf-stat.dTLB-loads
27.80 ± 2% +71.5 99.28 perf-stat.iTLB-load-miss-rate%
9.74e+09 ± 4% +94.9% 1.898e+10 perf-stat.iTLB-load-misses
2.528e+10 -99.5% 1.383e+08 ± 16% perf-stat.iTLB-loads
8.152e+12 +2.4% 8.345e+12 perf-stat.instructions
838.42 ± 4% -47.6% 439.73 perf-stat.instructions-per-iTLB-miss
0.55 +2.3% 0.56 perf-stat.ipc
762567 +1.5% 773691 perf-stat.minor-faults
4676629 ± 30% -55.2% 2092806 ± 4% perf-stat.node-stores
762578 +1.5% 773695 perf-stat.page-faults
144800 -1.3% 142864 perf-stat.path-length
will-it-scale.per_thread_ops
4e+06 +-+---------------------------------------------------------------+
O O O O O O O O O O O O O O O O O O O O O O O O O O |
3.5e+06 +-+.+.+.+.+.+.+..+.+.+.+.+.+.+.+.+.+.+.+.+.+.+.+..+.+.+.+.+.+.+.+.|
3e+06 +-+ |
| |
2.5e+06 +-+ |
| |
2e+06 +-+ |
| |
1.5e+06 +-+ |
1e+06 +-+ |
| |
500000 +-+ |
| |
0 +-+-----------O---------------------------------------------------+
will-it-scale.workload
6e+07 O-O-O-O--O-O-O---O-O-O-O--O-O-O-O-O-O-O-O--O-O-O-O-O-O-O------------+
|.+.+.+..+.+.+.+.+.+.+.+..+.+.+.+.+.+.+.+..+.+.+.+.+.+.+.+..+.+.+.+.|
5e+07 +-+ |
| |
| |
4e+07 +-+ |
| |
3e+07 +-+ |
| |
2e+07 +-+ |
| |
| |
1e+07 +-+ |
| |
0 +-+------------O----------------------------------------------------+
will-it-scale.time.user_time
1800 +-+------------------------------------------------------------------+
O.O.O.O..O.O.O.+.O.O..O.O.O.O.O.O..O.O.O.O.O.O.O..O.O.O.O.+.+..+.+.+.|
1600 +-+ |
1400 +-+ |
| |
1200 +-+ |
1000 +-+ |
| |
800 +-+ |
600 +-+ |
| |
400 +-+ |
200 +-+ |
| |
0 +-+------------O-----------------------------------------------------+
will-it-scale.time.system_time
3500 +-+------------------------------------------------------------------+
|.+.+.+..+.+.O.+.+.+..+.+.+.+.+.+..+.+.+.+.+.+.+..+.+.+.+.+.+..+.+.+.|
3000 O-O O O O O O O O O O O O O O O O O O O O O O O O |
| |
2500 +-+ |
| |
2000 +-+ |
| |
1500 +-+ |
| |
1000 +-+ |
| |
500 +-+ |
| |
0 +-+------------O-----------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
***************************************************************************************************
lkp-bdw-ep3d: 88 threads Intel(R) Xeon(R) CPU E5-2699 v4 @ 2.20GHz with 64G memory
=========================================================================================
compiler/cpufreq_governor/kconfig/mode/nr_task/rootfs/tbox_group/test/testcase:
gcc-7/performance/x86_64-rhel-7.2/thread/16/debian-x86_64-2018-04-03.cgz/lkp-bdw-ep3d/getppid1/will-it-scale
commit:
cba614f88d ("x86/entry/64: Use the TSS sp2 slot for rsp_scratch")
de87ae2926 ("x86/pti/64: Remove the SYSCALL64 entry trampoline")
cba614f88dfdeadd de87ae29269664b890e5323ff9
---------------- --------------------------
%stddev %change %stddev
\ | \
4145966 +4.3% 4324715 will-it-scale.per_thread_ops
66335462 +4.3% 69195456 will-it-scale.workload
0.00 ± 30% +0.0 0.01 ± 27% mpstat.cpu.soft%
1570 ±141% +51.1% 2372 ± 98% numa-numastat.node0.other_node
2070 ± 4% +25.0% 2588 ± 17% numa-meminfo.node1.PageTables
25821 ± 8% +8.7% 28067 ± 5% numa-meminfo.node1.SReclaimable
1208 ± 4% +5.7% 1276 ± 5% slabinfo.eventpoll_pwq.active_objs
1208 ± 4% +5.7% 1276 ± 5% slabinfo.eventpoll_pwq.num_objs
6962 +2.7% 7149 proc-vmstat.nr_shmem
430.33 +770.7% 3747 ± 87% proc-vmstat.numa_hint_faults_local
3875 +5.8% 4099 ± 4% proc-vmstat.pgactivate
16121 ± 13% -32.4% 10896 ± 11% numa-vmstat.node0
1687 ±129% +47.6% 2489 ± 92% numa-vmstat.node0.numa_other
9365 ± 22% +55.3% 14544 ± 8% numa-vmstat.node1
517.33 ± 4% +25.1% 647.00 ± 17% numa-vmstat.node1.nr_page_table_pages
6454 ± 8% +8.7% 7016 ± 5% numa-vmstat.node1.nr_slab_reclaimable
8466921 ± 97% -83.8% 1374133 ± 2% cpuidle.C1.time
148474 ± 64% -52.1% 71137 ± 2% cpuidle.C1.usage
2.471e+08 ± 29% -98.4% 3942202 cpuidle.C1E.time
1802745 ± 64% -98.7% 24177 cpuidle.C1E.usage
1.408e+08 ± 59% +698.7% 1.124e+09 ± 4% cpuidle.C3.time
167633 ± 52% +1466.7% 2626385 ± 2% cpuidle.C3.usage
1.971e+09 ± 4% -34.8% 1.286e+09 ± 2% cpuidle.C6.time
2098510 ± 4% +8.6% 2278392 ± 5% cpuidle.C6.usage
38191909 ±140% -99.9% 21778 ± 6% cpuidle.POLL.time
617067 ±140% -99.7% 2139 cpuidle.POLL.usage
145146 ± 66% -53.1% 68095 turbostat.C1
0.12 ± 99% -0.1 0.02 turbostat.C1%
1802589 ± 64% -98.7% 24071 turbostat.C1E
3.40 ± 29% -3.4 0.05 turbostat.C1E%
167399 ± 52% +1468.9% 2626260 ± 2% turbostat.C3
1.93 ± 59% +13.5 15.45 ± 4% turbostat.C3%
2097688 ± 4% +8.6% 2277836 ± 5% turbostat.C6
27.12 ± 4% -9.5 17.66 ± 2% turbostat.C6%
0.01 ± 81% +1550.0% 0.17 ± 69% turbostat.CPU%c3
0.39 ± 50% -52.2% 0.18 ± 24% turbostat.CPU%c6
7.908e+11 -5.5% 7.469e+11 perf-stat.branch-instructions
5.21 ± 2% -2.3 2.89 perf-stat.branch-miss-rate%
4.12e+10 -47.5% 2.162e+10 perf-stat.branch-misses
40984991 ± 3% -5.2% 38849817 ± 2% perf-stat.cache-misses
0.01 ± 23% -0.0 0.00 ± 8% perf-stat.dTLB-load-miss-rate%
1.229e+08 ± 23% -76.8% 28492076 ± 7% perf-stat.dTLB-load-misses
0.00 ± 19% -0.0 0.00 ± 12% perf-stat.dTLB-store-miss-rate%
8136287 ± 19% -38.6% 4992992 ± 11% perf-stat.dTLB-store-misses
9.911e+11 -2.1% 9.703e+11 perf-stat.dTLB-stores
2.92 ± 22% +90.8 93.67 perf-stat.iTLB-load-miss-rate%
9.176e+08 ± 24% +2336.6% 2.236e+10 ± 2% perf-stat.iTLB-load-misses
3.041e+10 -95.0% 1.511e+09 perf-stat.iTLB-loads
4858 ± 26% -96.2% 185.77 ± 2% perf-stat.instructions-per-iTLB-miss
0.28 +0.4% 0.28 perf-stat.ipc
94.74 -2.1 92.67 perf-stat.node-load-miss-rate%
631159 ± 4% +34.9% 851575 perf-stat.node-loads
62949 -4.7% 59990 perf-stat.path-length
421.22 ± 21% +24.4% 524.13 ± 8% sched_debug.cfs_rq:/.exec_clock.min
40629 ± 2% +19.9% 48710 ± 10% sched_debug.cfs_rq:/.load.avg
65283 ± 2% +136.6% 154433 ± 51% sched_debug.cfs_rq:/.load.max
25268 ± 3% +63.6% 41328 ± 35% sched_debug.cfs_rq:/.load.stddev
262.06 ± 27% +17.0% 306.67 ± 19% sched_debug.cfs_rq:/.load_avg.max
9970 ± 17% +14.2% 11388 ± 8% sched_debug.cfs_rq:/.min_vruntime.min
0.69 ± 2% +10.7% 0.77 ± 5% sched_debug.cfs_rq:/.nr_running.avg
39579 ± 2% +16.3% 46028 ± 10% sched_debug.cfs_rq:/.runnable_weight.avg
56834 ± 2% +160.2% 147884 ± 55% sched_debug.cfs_rq:/.runnable_weight.max
23517 ± 3% +68.5% 39632 ± 39% sched_debug.cfs_rq:/.runnable_weight.stddev
333.16 ± 23% +34.7% 448.79 ± 14% sched_debug.cfs_rq:/.util_est_enqueued.avg
791.83 ± 23% +25.7% 995.42 ± 2% sched_debug.cfs_rq:/.util_est_enqueued.max
306.76 ± 26% +27.2% 390.29 ± 7% sched_debug.cfs_rq:/.util_est_enqueued.stddev
258487 ± 15% -36.7% 163619 ± 27% sched_debug.cpu.avg_idle.min
175699 ± 5% +17.7% 206786 ± 3% sched_debug.cpu.avg_idle.stddev
0.11 ±141% +425.0% 0.58 ± 14% sched_debug.cpu.cpu_load[2].min
0.33 ±141% +150.0% 0.83 ± 40% sched_debug.cpu.cpu_load[4].min
40053 ± 2% +17.4% 47018 ± 9% sched_debug.cpu.load.avg
65371 ± 2% +136.2% 154433 ± 51% sched_debug.cpu.load.max
25663 ± 2% +64.5% 42219 ± 36% sched_debug.cpu.load.stddev
0.00 ± 6% +7.5% 0.00 ± 7% sched_debug.cpu.next_balance.stddev
1645 ± 9% +43.0% 2353 ± 7% sched_debug.cpu.nr_load_updates.stddev
0.69 ± 2% +11.6% 0.77 ± 3% sched_debug.cpu.nr_running.avg
0.01 -75.0% 0.00 ±100% sched_debug.cpu.nr_uninterruptible.avg
3.86 ± 5% +5.4% 4.06 ± 5% sched_debug.cpu.nr_uninterruptible.stddev
8404 ± 7% +8.5% 9118 ± 6% sched_debug.cpu.sched_count.avg
195.00 ± 32% +34.9% 263.00 ± 6% sched_debug.cpu.ttwu_count.min
7183 ± 79% -62.8% 2669 ± 10% sched_debug.cpu.ttwu_local.max
30.00 -30.0 0.00 perf-profile.calltrace.cycles-pp.__entry_trampoline_start
19.13 -3.4 15.74 ± 2% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64_after_hwframe
16.13 -2.6 13.57 perf-profile.calltrace.cycles-pp.do_syscall_64.entry_SYSCALL_64_after_hwframe
11.06 -1.0 10.02 perf-profile.calltrace.cycles-pp.__x64_sys_getppid.do_syscall_64.entry_SYSCALL_64_after_hwframe
16.31 +5.2 21.48 ± 15% perf-profile.calltrace.cycles-pp.secondary_startup_64
16.31 +5.2 21.48 ± 15% perf-profile.calltrace.cycles-pp.start_secondary.secondary_startup_64
16.31 +5.2 21.48 ± 15% perf-profile.calltrace.cycles-pp.cpu_startup_entry.start_secondary.secondary_startup_64
16.31 +5.2 21.48 ± 15% perf-profile.calltrace.cycles-pp.do_idle.cpu_startup_entry.start_secondary.secondary_startup_64
16.25 +5.2 21.46 ± 15% perf-profile.calltrace.cycles-pp.cpuidle_enter_state.do_idle.cpu_startup_entry.start_secondary.secondary_startup_64
15.74 ± 4% +5.7 21.45 ± 15% perf-profile.calltrace.cycles-pp.intel_idle.cpuidle_enter_state.do_idle.cpu_startup_entry.start_secondary
0.00 +30.8 30.82 ± 4% perf-profile.calltrace.cycles-pp.entry_SYSCALL_64
30.13 -30.1 0.00 perf-profile.children.cycles-pp.__entry_trampoline_start
19.25 -3.2 16.05 ± 2% perf-profile.children.cycles-pp.entry_SYSCALL_64_after_hwframe
16.30 -2.5 13.78 perf-profile.children.cycles-pp.do_syscall_64
10.57 -0.4 10.15 perf-profile.children.cycles-pp.__x64_sys_getppid
0.46 ± 4% -0.2 0.30 ± 3% perf-profile.children.cycles-pp.apic_timer_interrupt
0.42 ± 4% -0.1 0.28 ± 3% perf-profile.children.cycles-pp.smp_apic_timer_interrupt
0.34 ± 6% -0.1 0.24 ± 2% perf-profile.children.cycles-pp.hrtimer_interrupt
0.21 ± 4% -0.1 0.16 ± 6% perf-profile.children.cycles-pp.__hrtimer_run_queues
0.17 ± 4% -0.1 0.12 ± 8% perf-profile.children.cycles-pp.tick_sched_timer
0.14 ± 3% -0.0 0.11 ± 4% perf-profile.children.cycles-pp.tick_sched_handle
0.14 ± 5% -0.0 0.11 ± 4% perf-profile.children.cycles-pp.update_process_times
0.08 ± 6% -0.0 0.06 ± 9% perf-profile.children.cycles-pp.clockevents_program_event
0.00 +0.7 0.66 perf-profile.children.cycles-pp.__x86_indirect_thunk_rax
16.31 +5.2 21.48 ± 15% perf-profile.children.cycles-pp.secondary_startup_64
16.31 +5.2 21.48 ± 15% perf-profile.children.cycles-pp.cpu_startup_entry
16.31 +5.2 21.48 ± 15% perf-profile.children.cycles-pp.do_idle
16.31 +5.2 21.48 ± 15% perf-profile.children.cycles-pp.start_secondary
16.26 +5.2 21.46 ± 15% perf-profile.children.cycles-pp.cpuidle_enter_state
15.75 ± 4% +5.7 21.45 ± 15% perf-profile.children.cycles-pp.intel_idle
0.00 +30.9 30.86 ± 4% perf-profile.children.cycles-pp.entry_SYSCALL_64
30.13 -30.1 0.00 perf-profile.self.cycles-pp.__entry_trampoline_start
5.43 ± 2% -2.3 3.17 ± 4% perf-profile.self.cycles-pp.do_syscall_64
3.04 -0.5 2.54 ± 6% perf-profile.self.cycles-pp.entry_SYSCALL_64_after_hwframe
0.00 +0.6 0.60 perf-profile.self.cycles-pp.__x86_indirect_thunk_rax
15.75 ± 4% +5.7 21.45 ± 15% perf-profile.self.cycles-pp.intel_idle
0.00 +30.9 30.86 ± 4% perf-profile.self.cycles-pp.entry_SYSCALL_64
Disclaimer:
Results have been estimated based on internal Intel analysis and are provided
for informational purposes only. Any difference in system hardware or software
design or configuration may affect actual performance.
Thanks,
Rong, Chen
3 years
[tty] 0b4f83d510: INFO:task_blocked_for_more_than#seconds
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 0b4f83d510f6fef6bb9da25f122c8d733d50516f ("[PATCH 2/4] tty: Hold tty_ldisc_lock() during tty_reopen()")
url: https://github.com/0day-ci/linux/commits/Dmitry-Safonov/tty-Hold-write-ld...
base: https://git.kernel.org/cgit/linux/kernel/git/gregkh/tty.git tty-testing
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 -m 256M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------------------+------------+------------+
| | 58dd163974 | 0b4f83d510 |
+--------------------------------------------------+------------+------------+
| boot_successes | 14 | 4 |
| boot_failures | 0 | 6 |
| INFO:task_blocked_for_more_than#seconds | 0 | 6 |
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 6 |
+--------------------------------------------------+------------+------------+
[ 244.816801] INFO: task validate_data:655 blocked for more than 120 seconds.
[ 244.818833] Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.820028] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 244.826965] validate_data D 0 655 623 0x20020000
[ 244.828279] Call Trace:
[ 244.828958] ? __schedule+0x843/0x950
[ 244.830173] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.834903] schedule+0x31/0x70
[ 244.835665] schedule_timeout+0x34/0x760
[ 244.836613] ? ftrace_likely_update+0x35/0x60
[ 244.837683] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.838818] ? ftrace_likely_update+0x35/0x60
[ 244.840127] ? ftrace_likely_update+0x35/0x60
[ 244.845947] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.847882] __ldsem_down_read_nested+0x23a/0x3b0
[ 244.849886] ? tty_ldisc_ref_wait+0x25/0x50
[ 244.853807] tty_ldisc_ref_wait+0x25/0x50
[ 244.854946] tty_compat_ioctl+0x8a/0x120
[ 244.855928] ? this_tty+0x80/0x80
[ 244.856742] __ia32_compat_sys_ioctl+0xc28/0x1ce0
[ 244.857981] do_int80_syscall_32+0x1d2/0x5f0
[ 244.859003] entry_INT80_compat+0x88/0xa0
[ 244.859972] INFO: task dnsmasq:668 blocked for more than 120 seconds.
[ 244.868315] Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.869583] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 244.871744] dnsmasq D 0 668 1 0x20020000
[ 244.873063] Call Trace:
[ 244.873697] ? __schedule+0x843/0x950
[ 244.874572] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.875725] schedule+0x31/0x70
[ 244.876576] schedule_timeout+0x34/0x760
[ 244.877573] ? ftrace_likely_update+0x35/0x60
[ 244.878660] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.879872] ? ftrace_likely_update+0x35/0x60
[ 244.890522] ? ftrace_likely_update+0x35/0x60
[ 244.891572] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.892746] __ldsem_down_read_nested+0x23a/0x3b0
[ 244.893861] ? tty_ldisc_ref_wait+0x25/0x50
[ 244.894841] tty_ldisc_ref_wait+0x25/0x50
[ 244.895911] tty_compat_ioctl+0x8a/0x120
[ 244.896916] ? this_tty+0x80/0x80
[ 244.897717] __ia32_compat_sys_ioctl+0xc28/0x1ce0
[ 244.898821] do_int80_syscall_32+0x1d2/0x5f0
[ 244.899830] entry_INT80_compat+0x88/0xa0
[ 244.909466] INFO: task dropbear:734 blocked for more than 120 seconds.
[ 244.911173] Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.912394] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 244.914176] dropbear D 0 734 1 0x20020000
[ 244.915446] Call Trace:
[ 244.916068] ? __schedule+0x843/0x950
[ 244.916945] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.918076] schedule+0x31/0x70
[ 244.918832] schedule_timeout+0x34/0x760
[ 244.919781] ? ftrace_likely_update+0x35/0x60
[ 244.921104] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.922304] ? ftrace_likely_update+0x35/0x60
[ 244.923347] ? ftrace_likely_update+0x35/0x60
[ 244.924369] ? __ldsem_down_read_nested+0x1c4/0x3b0
[ 244.925496] __ldsem_down_read_nested+0x23a/0x3b0
[ 244.926598] ? tty_ldisc_ref_wait+0x25/0x50
[ 244.927578] tty_ldisc_ref_wait+0x25/0x50
[ 244.928526] tty_compat_ioctl+0x8a/0x120
[ 244.929449] ? this_tty+0x80/0x80
[ 244.930240] __ia32_compat_sys_ioctl+0xc28/0x1ce0
[ 244.940083] do_int80_syscall_32+0x1d2/0x5f0
[ 244.941310] entry_INT80_compat+0x88/0xa0
[ 244.944070]
[ 244.944070] Showing all locks held in the system:
[ 244.945558] 1 lock held by khungtaskd/18:
[ 244.946495] #0: (____ptrval____) (rcu_read_lock){....}, at: debug_show_all_locks+0x16/0x190
[ 244.948503] 2 locks held by askfirst/235:
[ 244.949439] #0: (____ptrval____) (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x50
[ 244.951762] #1: (____ptrval____) (&ldata->atomic_read_lock){+.+.}, at: n_tty_read+0x13d/0xa00
[ 244.953799] 1 lock held by validate_data/655:
[ 244.954814] #0: (____ptrval____) (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x50
[ 244.956764] 1 lock held by dnsmasq/668:
[ 244.957649] #0: (____ptrval____) (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x50
[ 244.959598] 1 lock held by dropbear/734:
[ 244.967564] #0: (____ptrval____) (&tty->ldisc_sem){++++}, at: tty_ldisc_ref_wait+0x25/0x50
[ 244.969581]
[ 244.969975] =============================================
[ 244.969975]
[ 244.971833] NMI backtrace for cpu 0
[ 244.972696] CPU: 0 PID: 18 Comm: khungtaskd Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.974371] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 244.976260] Call Trace:
[ 244.976895] dump_stack+0xb9/0x10e
[ 244.977723] ? lapic_can_unplug_cpu+0xa0/0xa0
[ 244.978735] nmi_cpu_backtrace+0x13a/0x150
[ 244.979697] ? lapic_can_unplug_cpu+0xa0/0xa0
[ 244.980713] nmi_trigger_cpumask_backtrace+0x188/0x280
[ 244.981899] watchdog+0x83b/0x880
[ 244.982683] ? reset_hung_task_detector+0x20/0x20
[ 244.983762] kthread+0x170/0x180
[ 244.984509] ? kthread_create_worker_on_cpu+0x70/0x70
[ 244.985659] ret_from_fork+0x24/0x30
[ 244.990807] Kernel panic - not syncing: hung_task: blocked tasks
[ 244.992205] CPU: 0 PID: 18 Comm: khungtaskd Not tainted 4.18.0-11684-g0b4f83d #1
[ 244.993881] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 244.995769] Call Trace:
[ 244.996362] dump_stack+0xb9/0x10e
[ 244.997166] panic+0xfd/0x2bb
[ 244.997878] ? nmi_trigger_cpumask_backtrace+0x269/0x280
[ 244.999097] ? watchdog+0x83b/0x880
[ 244.999982] watchdog+0x847/0x880
[ 245.000782] ? reset_hung_task_detector+0x20/0x20
[ 245.001862] kthread+0x170/0x180
[ 245.002613] ? kthread_create_worker_on_cpu+0x70/0x70
[ 245.003785] ret_from_fork+0x24/0x30
[ 245.004646] Kernel Offset: 0x10800000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[ 245.007065] Rebooting in 3 seconds..
Elapsed time: 250
#!/bin/bash
# To reproduce,
# 1) save job-script and this script (both are attached in 0day report email)
# 2) run this script with your compiled kernel and optional env $INSTALL_MOD_PATH
kernel=$1
initrds=(
/osimage/openwrt/openwrt-i386-2016-03-16.cgz
/lkp/lkp/lkp-i386.cgz
/osimage/pkg/debian-x86_64-2016-08-31.cgz/trinity-static-i386-x86_64-6ddabfd2_2017-11-10.cgz
)
HTTP_PREFIX=https://download.01.org/0day-ci/lkp-qemu
wget --timestamping "${initrds[@]/#/$HTTP_PREFIX}"
{
cat "${initrds[@]//*\//}"
[[ $INSTALL_MOD_PATH ]] && (
cd "$INSTALL_MOD_PATH"
find lib | cpio -o -H newc --quiet | gzip
)
echo job-script | cpio -o -H newc --quiet | gzip
} > initrd.img
qemu-img create -f qcow2 disk-vm-lkp-hsw-4ep1-openwrt-ia32-13-0 256G
qemu-img create -f qcow2 disk-vm-lkp-hsw-4ep1-openwrt-ia32-13-1 256G
kvm=(
qemu-system-x86_64
To reproduce:
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,
Rong, Chen
3 years
[ipc] eb7e666ca9: general_protection_fault:#[##]
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: eb7e666ca9015b4aa0a438ff1f11d4a4a2178503 ("ipc: Convert mqueue fs to fs_context")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master
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 Haswell,+smep,+smap -smp 2 -m 2G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------+------------+------------+
| | 1b34a4bb5b | eb7e666ca9 |
+------------------------------------------+------------+------------+
| boot_successes | 13 | 2 |
| boot_failures | 2 | 50 |
| invoked_oom-killer:gfp_mask=0x | 2 | 1 |
| Mem-Info | 2 | 1 |
| general_protection_fault:#[##] | 0 | 28 |
| RIP:mqueue_get_tree | 0 | 46 |
| Kernel_panic-not_syncing:Fatal_exception | 0 | 50 |
| BUG:unable_to_handle_kernel | 0 | 22 |
| Oops:#[##] | 0 | 22 |
| RIP:lockref_get | 0 | 4 |
+------------------------------------------+------------+------------+
[ 28.401815] audit: type=1326 audit(1536315279.341:5): auid=4294967295 uid=65534 gid=65534 ses=4294967295 subj=kernel pid=829 comm="trinity-c5" exe="/bin/trinity" sig=9 arch=c000003e syscall=8 compat=0 ip=0x7ffb292ffaf7 code=0x0
[ 30.547506] Guest personality initialized and is inactive
[ 30.557091] VMCI host device registered (name=vmci, major=10, minor=58)
[ 30.558894] Initialized host personality
[ 30.562135] NET: Registered protocol family 40
[ 31.879456] general protection fault: 0000 [#1] SMP PTI
[ 31.880921] CPU: 0 PID: 976 Comm: trinity-c1 Not tainted 4.19.0-rc1-00108-geb7e666 #1
[ 31.883035] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 31.885249] RIP: 0010:mqueue_get_tree+0x2c/0xb0
[ 31.886492] Code: 44 00 00 41 54 55 53 4c 8b 67 10 48 89 fb 48 c7 c7 20 f5 13 83 e8 74 a0 63 00 49 8b 04 24 48 8b 80 f0 02 00 00 48 85 c0 74 25 <48> 8b 40 08 48 8b 68 68 48 85 ed 74 09 48 8d 7d 58 e8 9e 73 0b 00
[ 31.891047] RSP: 0018:ffffc900007abdf0 EFLAGS: 00010202
[ 31.892435] RAX: 23403f296f232364 RBX: ffff88007e25be00 RCX: 0000000000000000
[ 31.894212] RDX: 0000000000000001 RSI: 0000000000000000 RDI: ffffffff8313f520
[ 31.895985] RBP: ffff88002c02d000 R08: ffff880072826360 R09: ffff880063c03980
[ 31.897760] R10: 000000000000002c R11: ffff880063d1a500 R12: ffff88002c509528
[ 31.899532] R13: 0000000000000000 R14: ffff88007e94a620 R15: 0000000000000000
[ 31.901303] FS: 00007ffb299d8b40(0000) GS:ffff880072800000(0000) knlGS:0000000000000000
[ 31.903482] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 31.904967] CR2: 00007ffb2804257c CR3: 000000002c0a4004 CR4: 00000000000606f0
[ 31.906753] DR0: 00007ffb2768f000 DR1: 0000000000000000 DR2: 0000000000000000
[ 31.908525] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
[ 31.910308] Call Trace:
[ 31.911140] vfs_get_tree+0x5e/0x150
[ 31.912209] mq_create_mount+0x5b/0xb0
[ 31.913288] mq_init_ns+0x37/0x50
[ 31.914301] copy_ipcs+0xc0/0x150
[ 31.915291] create_new_namespaces+0xac/0x1b0
[ 31.916500] unshare_nsproxy_namespaces+0x59/0xb0
[ 31.917770] ksys_unshare+0x1c6/0x370
[ 31.918832] __x64_sys_unshare+0xe/0x20
[ 31.919947] do_syscall_64+0x5b/0x180
[ 31.921009] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 31.922380] RIP: 0033:0x7ffb292fb229
[ 31.923416] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 3f 4c 2b 00 f7 d8 64 89 01 48
[ 31.927970] RSP: 002b:00007fffd9fd9028 EFLAGS: 00000246 ORIG_RAX: 0000000000000110
[ 31.930028] RAX: ffffffffffffffda RBX: 0000000000000110 RCX: 00007ffb292fb229
[ 31.931795] RDX: 468120420675484d RSI: 0000000000000000 RDI: 0000000058050900
[ 31.933566] RBP: 00007fffd9fd90d0 R08: 0004d85828000dc3 R09: 00000000b7b7b7b7
[ 31.935332] R10: 00000000e0e0e0e0 R11: 0000000000000246 R12: 0000000000000002
[ 31.937113] R13: 00007ffb299ca058 R14: 00007ffb299d8ad8 R15: 00007ffb299ca000
[ 31.938887] Modules linked in: vmw_vsock_vmci_transport vsock vmw_vmci af_key ieee802154_socket ieee802154 can_bcm can_raw can pptp gre l2tp_ppp l2tp_netlink l2tp_core ip6_udp_tunnel udp_tunnel pppoe pppox ppp_generic slhc crypto_user nfnetlink scsi_transport_iscsi dccp_ipv6 atm sctp dccp_ipv4 dccp sr_mod cdrom sg ata_generic pata_acpi crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel pcbc ppdev aesni_intel crypto_simd snd_pcm cryptd glue_helper snd_timer snd soundcore pcspkr ata_piix serio_raw i2c_piix4 libata floppy parport_pc parport ip_tables
[ 31.953200] ---[ end trace 2f6a6cde8c8f43f3 ]---
[ 31.954493] RIP: 0010:mqueue_get_tree+0x2c/0xb0
[ 31.955749] Code: 44 00 00 41 54 55 53 4c 8b 67 10 48 89 fb 48 c7 c7 20 f5 13 83 e8 74 a0 63 00 49 8b 04 24 48 8b 80 f0 02 00 00 48 85 c0 74 25 <48> 8b 40 08 48 8b 68 68 48 85 ed 74 09 48 8d 7d 58 e8 9e 73 0b 00
[ 31.962442] RSP: 0018:ffffc900007abdf0 EFLAGS: 00010202
[ 31.963842] RAX: 23403f296f232364 RBX: ffff88007e25be00 RCX: 0000000000000000
[ 31.965952] RDX: 0000000000000001 RSI: 0000000000000000 RDI: ffffffff8313f520
[ 31.967760] RBP: ffff88002c02d000 R08: ffff880072826360 R09: ffff880063c03980
[ 31.969859] R10: 000000000000002c R11: ffff880063d1a500 R12: ffff88002c509528
[ 31.971644] R13: 0000000000000000 R14: ffff88007e94a620 R15: 0000000000000000
[ 31.973744] FS: 00007ffb299d8b40(0000) GS:ffff880072800000(0000) knlGS:0000000000000000
[ 31.975939] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 31.977662] CR2: 00007ffb2804257c CR3: 000000002c0a4004 CR4: 00000000000606f0
[ 31.979739] DR0: 00007ffb2768f000 DR1: 0000000000000000 DR2: 0000000000000000
[ 31.981539] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600
[ 31.983637] Kernel panic - not syncing: Fatal exception
[ 31.985065] Kernel Offset: disabled
Elapsed time: 40
#!/bin/bash
To reproduce:
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,
Rong, Chen
3 years
[rcutorture] 894b343aa8: WARNING:at_kernel/rcu/rcutorture.c:#rcu_torture_fwd_prog
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 894b343aa8bec5ee732329f1db09b9f5c2794de5 ("rcutorture: Add call_rcu() flooding forward-progress tests")
https://git.kernel.org/cgit/linux/kernel/git/paulmck/linux-rcu.git dev.2018.08.30a
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 Haswell,+smep,+smap -smp 2 -m 512M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------------------------+------------+------------+
| | 93fd89934b | 894b343aa8 |
+------------------------------------------------------------------+------------+------------+
| boot_successes | 24 | 18 |
| boot_failures | 1 | 12 |
| invoked_oom-killer:gfp_mask=0x | 1 | 2 |
| Mem-Info | 1 | 2 |
| Out_of_memory:Kill_process | 1 | |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 0 | 2 |
| RIP:rcu_torture_fwd_prog | 0 | 10 |
| WARNING:at_kernel/rcu/rcutorture.c:#rcu_torture_fwd_prog | 0 | 9 |
+------------------------------------------------------------------+------------+------------+
[ 307.810166] WARNING: CPU: 1 PID: 54 at kernel/rcu/rcutorture.c:1840 rcu_torture_fwd_prog+0x41f/0x542
[ 307.832010] Modules linked in:
[ 307.837737] CPU: 1 PID: 54 Comm: rcu_torture_fwd Tainted: G T 4.19.0-rc1-00151-g894b343 #1
[ 307.856076] RIP: 0010:rcu_torture_fwd_prog+0x41f/0x542
[ 307.866058] Code: b8 0e 00 eb e2 48 c7 05 c9 25 35 01 f0 fa 78 83 c6 05 92 99 67 02 00 e8 29 6c 09 00 84 c0 0f 85 af 00 00 00 49 83 fc 63 7f 02 <0f> 0b 48 8b 45 88 4f 8d 44 3d 00 4d 89 e9 48 c7 c6 a0 34 e2 81 48
[ 307.902163] RSP: 0018:ffff88000c1cbe80 EFLAGS: 00010293
[ 307.912698] RAX: 0000000000000000 RBX: 0000000000000001 RCX: ffff88001046c080
[ 307.926369] RDX: 0000000000000017 RSI: ffffffff811c173d RDI: ffff88001046c080
[ 307.940082] RBP: ffff88000c1cbf00 R08: 0000000000000020 R09: ffff8800053e4ce0
[ 307.953984] R10: ffff8800053e4260 R11: ffff8800053e4d40 R12: 0000000000000000
[ 307.968462] R13: 0000000000000003 R14: 0000000000000000 R15: 0000000000000083
[ 307.982466] FS: 0000000000000000(0000) GS:ffff88001c400000(0000) knlGS:0000000000000000
[ 307.998082] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 308.009554] CR2: 00007ffc7538e000 CR3: 0000000002411004 CR4: 00000000000206a0
[ 308.023264] Call Trace:
[ 308.028512] ? _raw_spin_unlock_irqrestore+0x45/0x4f
[ 308.038529] ? rcu_torture_stall+0x12d/0x12d
[ 308.047149] ? kthread+0x114/0x123
[ 308.054115] ? kthread+0x114/0x123
[ 308.060625] ? kthread_create_worker_on_cpu+0x5f/0x5f
[ 308.069703] ? ret_from_fork+0x3a/0x50
[ 308.076537] irq event stamp: 3048
[ 308.082507] hardirqs last enabled at (3047): [<ffffffff81216404>] kfree+0x125/0x136
[ 308.097831] hardirqs last disabled at (3048): [<ffffffff810036a6>] trace_hardirqs_off_thunk+0x1a/0x1c
[ 308.115656] softirqs last enabled at (56): [<ffffffff81c00359>] __do_softirq+0x359/0x39b
[ 308.130979] softirqs last disabled at (49): [<ffffffff810cd5d1>] irq_exit+0x59/0x75
[ 308.145115] ---[ end trace 3654c8b0e1b99cb1 ]---
To reproduce:
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,
Rong, Chen
3 years
[blkcg] 6ef69a3a0b: WARNING:suspicious_RCU_usage
by kernel test robot
FYI, we noticed the following commit (built with gcc-7):
commit: 6ef69a3a0b4ac904f7c3b9cb78b5d51520dc84f4 ("[PATCH 13/15] blkcg: change blkg reference counting to use percpu_ref")
url: https://github.com/0day-ci/linux/commits/Dennis-Zhou/blkcg-ref-count-refa...
base: https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git for-next
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-i386 -enable-kvm -cpu SandyBridge -m 256M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------------------------------------------+------------+------------+
| | 22f657e287 | 6ef69a3a0b |
+------------------------------------------------------------------------------------+------------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 14 | 33 |
| WARNING:at_mm/slab_common.c:#kmalloc_slab | 14 | 33 |
| EIP:kmalloc_slab | 14 | 33 |
| Mem-Info | 14 | 33 |
| WARNING:at_arch/x86/mm/dump_pagetables.c:#note_page | 14 | 31 |
| EIP:note_page | 14 | 31 |
| WARNING:suspicious_RCU_usage | 0 | 33 |
| include/linux/rcupdate.h:#Illegal_context_switch_in_RCU_read-side_critical_section | 0 | 33 |
| BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/mutex.c | 0 | 33 |
+------------------------------------------------------------------------------------+------------+------------+
[ 5.313007] WARNING: suspicious RCU usage
[ 5.313705] 4.19.0-rc1-00175-g6ef69a3 #633 Tainted: G W
[ 5.314812] -----------------------------
[ 5.315231] include/linux/rcupdate.h:302 Illegal context switch in RCU read-side critical section!
[ 5.315231]
[ 5.315231] other info that might help us debug this:
[ 5.315231]
[ 5.315231]
[ 5.315231] rcu_scheduler_active = 2, debug_locks = 1
[ 5.315231] 4 locks held by swapper/1:
[ 5.315231] #0: (ptrval) (&dev->mutex){....}, at: __driver_attach+0x45/0xb0
[ 5.315231] #1: (ptrval) (ide_cfg_mtx){+.+.}, at: ide_port_setup_devices+0x1c/0x120
[ 5.315231] #2: (ptrval) (rcu_read_lock){....}, at: blkcg_init_queue+0x21/0x160
[ 5.315231] #3: (ptrval) (&(&q->__queue_lock)->rlock){....}, at: blkcg_init_queue+0x5e/0x160
[ 5.315231]
[ 5.315231] stack backtrace:
[ 5.315231] CPU: 0 PID: 1 Comm: swapper Tainted: G W 4.19.0-rc1-00175-g6ef69a3 #633
[ 5.315231] Call Trace:
[ 5.315231] ? dump_stack+0x16/0x26
[ 5.315231] ? lockdep_rcu_suspicious+0x91/0xa0
[ 5.315231] ? ___might_sleep+0x182/0x230
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? __might_sleep+0x2d/0x80
[ 5.315231] ? __mutex_lock+0x21/0x4e0
[ 5.315231] ? kvm_sched_clock_read+0x14/0x30
[ 5.315231] ? sched_clock+0x9/0x10
[ 5.315231] ? sched_clock_local+0x87/0x160
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? mutex_lock_killable_nested+0x14/0x20
[ 5.315231] ? pcpu_alloc+0x2c5/0x610
[ 5.315231] ? pcpu_alloc+0x2c5/0x610
[ 5.315231] ? kfree+0xdd/0x140
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? __alloc_percpu_gfp+0xb/0x10
[ 5.315231] ? percpu_ref_init+0x1e/0x90
[ 5.315231] ? blkg_create+0x18f/0x510
[ 5.315231] ? blkcg_init_queue+0x6c/0x160
[ 5.315231] ? blkcg_init_queue+0x21/0x160
[ 5.315231] ? blk_alloc_queue_node+0x2c5/0x370
[ 5.315231] ? ide_port_setup_devices+0x77/0x120
[ 5.315231] ? ide_host_register+0x567/0x5e0
[ 5.315231] ? ide_pci_init_two+0x56b/0x800
[ 5.315231] ? sched_clock_local+0x87/0x160
[ 5.315231] ? _raw_spin_unlock_irqrestore+0x2a/0x50
[ 5.315231] ? lockdep_hardirqs_on+0xec/0x1a0
[ 5.315231] ? _raw_spin_unlock_irqrestore+0x2a/0x50
[ 5.315231] ? trace_hardirqs_on+0x36/0xe0
[ 5.315231] ? __pm_runtime_resume+0x4e/0x80
[ 5.315231] ? ide_pci_init_one+0xd/0x10
[ 5.315231] ? piix_init_one+0x16/0x20
[ 5.315231] ? pci_device_probe+0xb5/0x140
[ 5.315231] ? really_probe+0x19b/0x290
[ 5.315231] ? driver_probe_device+0x49/0x140
[ 5.315231] ? __driver_attach+0xa9/0xb0
[ 5.315231] ? driver_probe_device+0x140/0x140
[ 5.315231] ? bus_for_each_dev+0x4f/0x80
[ 5.315231] ? driver_attach+0x14/0x20
[ 5.315231] ? driver_probe_device+0x140/0x140
[ 5.315231] ? bus_add_driver+0x157/0x1e0
[ 5.315231] ? pci_bus_num_vf+0x10/0x10
[ 5.315231] ? driver_register+0x51/0xe0
[ 5.315231] ? pdc202new_ide_init+0x16/0x16
[ 5.315231] ? __pci_register_driver+0x4b/0x50
[ 5.315231] ? piix_ide_init+0x8f/0x94
[ 5.315231] ? do_one_initcall+0xa1/0x1a7
[ 5.315231] ? rcu_read_lock_sched_held+0x4f/0x70
[ 5.315231] ? trace_initcall_level+0x57/0x80
[ 5.315231] ? kernel_init_freeable+0xdb/0x180
[ 5.315231] ? kernel_init_freeable+0x100/0x180
[ 5.315231] ? rest_init+0x90/0x90
[ 5.315231] ? kernel_init+0x8/0xf0
[ 5.315231] ? ret_from_fork+0x19/0x24
[ 5.315231] BUG: sleeping function called from invalid context at kernel/locking/mutex.c:908
[ 5.315231] in_atomic(): 1, irqs_disabled(): 1, pid: 1, name: swapper
[ 5.315231] 4 locks held by swapper/1:
[ 5.315231] #0: (ptrval) (&dev->mutex){....}, at: __driver_attach+0x45/0xb0
[ 5.315231] #1: (ptrval) (ide_cfg_mtx){+.+.}, at: ide_port_setup_devices+0x1c/0x120
[ 5.315231] #2: (ptrval) (rcu_read_lock){....}, at: blkcg_init_queue+0x21/0x160
[ 5.315231] #3: (ptrval) (&(&q->__queue_lock)->rlock){....}, at: blkcg_init_queue+0x5e/0x160
[ 5.315231] irq event stamp: 996210
[ 5.315231] hardirqs last enabled at (996209): [<47b49149>] kmem_cache_alloc_trace+0xa9/0x250
[ 5.315231] hardirqs last disabled at (996210): [<48cfea62>] _raw_spin_lock_irq+0x12/0x60
[ 5.315231] softirqs last enabled at (996106): [<48d01516>] __do_softirq+0x246/0x344
[ 5.315231] softirqs last disabled at (996097): [<47a0a74c>] do_softirq_own_stack+0x1c/0x30
[ 5.315231] CPU: 0 PID: 1 Comm: swapper Tainted: G W 4.19.0-rc1-00175-g6ef69a3 #633
[ 5.315231] Call Trace:
[ 5.315231] ? dump_stack+0x16/0x26
[ 5.315231] ? ___might_sleep+0x13b/0x230
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? __might_sleep+0x2d/0x80
[ 5.315231] ? __mutex_lock+0x21/0x4e0
[ 5.315231] ? kvm_sched_clock_read+0x14/0x30
[ 5.315231] ? sched_clock+0x9/0x10
[ 5.315231] ? sched_clock_local+0x87/0x160
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? mutex_lock_killable_nested+0x14/0x20
[ 5.315231] ? pcpu_alloc+0x2c5/0x610
[ 5.315231] ? pcpu_alloc+0x2c5/0x610
[ 5.315231] ? kfree+0xdd/0x140
[ 5.315231] ? blkg_alloc+0x140/0x140
[ 5.315231] ? __alloc_percpu_gfp+0xb/0x10
[ 5.315231] ? percpu_ref_init+0x1e/0x90
[ 5.315231] ? blkg_create+0x18f/0x510
[ 5.315231] ? blkcg_init_queue+0x6c/0x160
[ 5.315231] ? blkcg_init_queue+0x21/0x160
[ 5.315231] ? blk_alloc_queue_node+0x2c5/0x370
[ 5.315231] ? ide_port_setup_devices+0x77/0x120
[ 5.315231] ? ide_host_register+0x567/0x5e0
[ 5.315231] ? ide_pci_init_two+0x56b/0x800
[ 5.315231] ? sched_clock_local+0x87/0x160
[ 5.315231] ? _raw_spin_unlock_irqrestore+0x2a/0x50
[ 5.315231] ? lockdep_hardirqs_on+0xec/0x1a0
[ 5.315231] ? _raw_spin_unlock_irqrestore+0x2a/0x50
[ 5.315231] ? trace_hardirqs_on+0x36/0xe0
[ 5.315231] ? __pm_runtime_resume+0x4e/0x80
[ 5.315231] ? ide_pci_init_one+0xd/0x10
[ 5.315231] ? piix_init_one+0x16/0x20
[ 5.315231] ? pci_device_probe+0xb5/0x140
[ 5.315231] ? really_probe+0x19b/0x290
[ 5.315231] ? driver_probe_device+0x49/0x140
[ 5.315231] ? __driver_attach+0xa9/0xb0
[ 5.315231] ? driver_probe_device+0x140/0x140
[ 5.315231] ? bus_for_each_dev+0x4f/0x80
[ 5.315231] ? driver_attach+0x14/0x20
[ 5.315231] ? driver_probe_device+0x140/0x140
[ 5.315231] ? bus_add_driver+0x157/0x1e0
[ 5.315231] ? pci_bus_num_vf+0x10/0x10
[ 5.315231] ? driver_register+0x51/0xe0
[ 5.315231] ? pdc202new_ide_init+0x16/0x16
[ 5.315231] ? __pci_register_driver+0x4b/0x50
[ 5.315231] ? piix_ide_init+0x8f/0x94
[ 5.315231] ? do_one_initcall+0xa1/0x1a7
[ 5.315231] ? rcu_read_lock_sched_held+0x4f/0x70
[ 5.315231] ? trace_initcall_level+0x57/0x80
[ 5.315231] ? kernel_init_freeable+0xdb/0x180
[ 5.315231] ? kernel_init_freeable+0x100/0x180
[ 5.315231] ? rest_init+0x90/0x90
[ 5.315231] ? kernel_init+0x8/0xf0
[ 5.315231] ? ret_from_fork+0x19/0x24
[ 5.418590] ide_generic: please use "probe_mask=0x3f" module parameter for probing all legacy ISA IDE ports
[ 5.420208] Loading iSCSI transport class v2.0-870.
[ 5.424773] rdac: device handler registered
[ 5.425612] hp_sw: device handler registered
[ 5.426442] alua: device handler registered
[ 5.427168] st: Version 20160209, fixed bufsize 32768, s/g segs 256
[ 5.428294] osst :I: Tape driver with OnStream support version 0.99.4
[ 5.428294] osst :I: $Id: osst.c,v 1.73 2005/01/01 21:13:34 wriede Exp $
[ 5.431683] Rounding down aligned max_sectors from 4294967295 to 4294967288
[ 5.433091] db_root: cannot open: /etc/target
[ 5.434136] SSFDC read-only Flash Translation layer
[ 5.435107] L440GX flash mapping: failed to find PIIX4 ISA bridge, cannot continue
[ 5.436418] device id = 2440
[ 5.436921] device id = 2480
[ 5.437430] device id = 24c0
[ 5.437931] device id = 24d0
[ 5.438464] device id = 25a1
[ 5.438975] device id = 2670
[ 5.439673] slram: not enough parameters.
[ 5.557989] No valid DiskOnChip devices found
[ 5.575575] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.577267] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.578759] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.580241] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.581727] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.583206] [nandsim] warning: read_byte: unexpected data output cycle, state is STATE_READY return 0x0
[ 5.584700] nand: device found, Manufacturer ID: 0x98, Chip ID: 0x39
[ 5.585730] nand: Toshiba NAND 128MiB 1,8V 8-bit
[ 5.586474] nand: 128 MiB, SLC, erase size: 16 KiB, page size: 512, OOB size: 16
[ 5.588284] flash size: 128 MiB
[ 5.588800] page size: 512 bytes
[ 5.589327] OOB area size: 16 bytes
[ 5.589887] sector size: 16 KiB
[ 5.591573] pages number: 262144
To reproduce:
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,
Rong, Chen
3 years