[lkp] [ima] 222fafb6d3: BUG: spinlock bad magic on CPU#0, swapper/0/1
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/zohar/linux-integrity.git next-restore-kexec
commit 222fafb6d3b65e2ab7cf4703b7bbf185bff47f49 ("ima: store the builtin/custom template definitions in a list")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu Westmere -m 512M
caused below changes:
[ 7.396606] Loading compiled-in X.509 certificates
[ 7.397364] page_owner is disabled
[ 7.400723] Key type encrypted registered
[ 7.401350] BUG: spinlock bad magic on CPU#0, swapper/0/1
[ 7.402150] lock: template_list+0x0/0x60, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
[ 7.403382] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.8.0-rc1-00027-g222fafb6 #1
[ 7.404548] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 7.405855] dffffc0000000000 ffff8800001bfd20 ffffffff815311fd ffffffff833370a0
[ 7.407004] ffff8800001b0000 ffff8800001bfd58 ffffffff8119348b ffffffff824f6fc0
[ 7.408117] ffff8800001bfd90 ffffffff833370a0 0000000000000000 dffffc0000000000
[ 7.409277] Call Trace:
[ 7.409656] [<ffffffff815311fd>] dump_stack+0x63/0x86
[ 7.410381] [<ffffffff8119348b>] spin_dump+0x18b/0x240
[ 7.411185] [<ffffffff81193630>] do_raw_spin_lock+0x60/0x260
[ 7.412001] [<ffffffff81d8454b>] _raw_spin_lock+0x3b/0x50
[ 7.412822] [<ffffffff8280b2e8>] ? ima_init_template_list+0x38/0xbb
[ 7.413724] [<ffffffff8280b2e8>] ima_init_template_list+0x38/0xbb
[ 7.414753] [<ffffffff8280aa2b>] ? hash_setup+0x103/0x103
[ 7.415534] [<ffffffff8280aa35>] init_ima+0xa/0x35
[ 7.416220] [<ffffffff810005c3>] do_one_initcall+0x123/0x200
[ 7.417072] [<ffffffff810004a0>] ? initcall_blacklisted+0x170/0x170
[ 7.419615] [<ffffffff81125240>] ? parse_args+0x670/0xa30
[ 7.420387] [<ffffffff827cb844>] kernel_init_freeable+0x2b1/0x35f
[ 7.421323] [<ffffffff81d74aae>] kernel_init+0xe/0x110
[ 7.422075] [<ffffffff81d8513f>] ret_from_fork+0x1f/0x40
[ 7.422887] [<ffffffff81d74aa0>] ? rest_init+0xf0/0xf0
[ 7.423680] ima: No TPM chip found, activating TPM-bypass!
[ 7.436015] Magic number: 12:72:851
Thanks,
Xiaolong
5 years, 8 months
[lkp] [i2c] faec3e0feb: WARNING: CPU: 31 PID: 1 at drivers/i2c/i2c-core.c:1866 i2c_add_numbered_adapter+0x8d/0xa0
by kernel test robot
FYI, we noticed the following commit:
https://github.com/0day-ci/linux vadimp-mellanox-com/i2c-add-master-driver-for-mellanox-systems/20160828-225625
commit faec3e0febcaedb387cb244f2f493dc835351df3 ("i2c: add master driver for mellanox systems")
in testcase: will-it-scale
with following parameters:
test: page_fault1
cpufreq_governor: performance
## 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.
on test machine: 32 threads Intel(R) Xeon(R) CPU E5-2680 0 @ 2.70GHz with 64G memory
caused below changes:
kern :info : [ 11.987385] i801_smbus 0000:06:00.3: Enabling SMBus device
kern :info : [ 11.993545] i801_smbus 0000:06:00.3: SMBus using PCI interrupt
kern :warn : [ 12.002184] ------------[ cut here ]------------
kern :warn : [ 12.007351] WARNING: CPU: 31 PID: 1 at drivers/i2c/i2c-core.c:1866 i2c_add_numbered_adapter+0x8d/0xa0
kern :warn : [ 12.019788] couldn't get idr
kern :warn : [ 12.022814] Modules linked in:
kern :warn : [ 12.026450] CPU: 31 PID: 1 Comm: swapper/0 Not tainted 4.8.0-rc3-00040-gfaec3e0 #1
kern :info : [ 12.029208] usb 2-1: new high-speed USB device number 2 using ehci-pci
kern :warn : [ 12.042202] Hardware name: Intel Corporation S2600CP/S2600CP, BIOS SE5C600.86B.99.99.x036.091920111209 09/19/2011
kern :warn : [ 12.053684] 0000000000000000 ffff88081b677bc0 ffffffff8144bd09 ffff88081b677c10
kern :warn : [ 12.062001] 0000000000000000 ffff88081b677c00 ffffffff8107e69b 0000074a00000001
kern :warn : [ 12.070298] ffff881002142018 ffff88100214235c ffff88103d4db810 ffff88103d4db800
kern :warn : [ 12.078603] Call Trace:
kern :warn : [ 12.081352] [<ffffffff8144bd09>] dump_stack+0x63/0x8a
kern :warn : [ 12.087095] [<ffffffff8107e69b>] __warn+0xcb/0xf0
kern :warn : [ 12.092442] [<ffffffff8107e70f>] warn_slowpath_fmt+0x4f/0x60
kern :warn : [ 12.098854] [<ffffffff8176b47d>] i2c_add_numbered_adapter+0x8d/0xa0
kern :info : [ 12.102722] usb 1-1: New USB device found, idVendor=8087, idProduct=0024
kern :info : [ 12.102725] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
kern :info : [ 12.103127] hub 1-1:1.0: USB hub found
kern :info : [ 12.103349] hub 1-1:1.0: 6 ports detected
kern :warn : [ 12.130059] [<ffffffff8205a0fd>] mlxcpld_i2c_probe+0xfe/0x134
kern :warn : [ 12.136578] [<ffffffff815ab64b>] platform_drv_probe+0x3b/0xa0
kern :warn : [ 12.143095] [<ffffffff815a57ac>] ? devices_kset_move_last+0x4c/0xa0
kern :info : [ 12.147586] usb 2-1: New USB device found, idVendor=8087, idProduct=0024
kern :info : [ 12.147589] usb 2-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
kern :info : [ 12.147822] hub 2-1:1.0: USB hub found
kern :info : [ 12.147891] hub 2-1:1.0: 8 ports detected
kern :warn : [ 12.174282] [<ffffffff815a9513>] driver_probe_device+0x223/0x430
kern :warn : [ 12.181083] [<ffffffff815a97ff>] __driver_attach+0xdf/0xf0
kern :warn : [ 12.187302] [<ffffffff815a9720>] ? driver_probe_device+0x430/0x430
kern :warn : [ 12.194296] [<ffffffff815a7000>] bus_for_each_dev+0x60/0xa0
kern :warn : [ 12.200613] [<ffffffff815a8c4e>] driver_attach+0x1e/0x20
kern :warn : [ 12.206639] [<ffffffff815a8690>] bus_add_driver+0x170/0x270
kern :warn : [ 12.212956] [<ffffffff8205a133>] ? mlxcpld_i2c_probe+0x134/0x134
kern :warn : [ 12.219765] [<ffffffff815aa120>] driver_register+0x60/0xe0
kern :warn : [ 12.225985] [<ffffffff8205a133>] ? mlxcpld_i2c_probe+0x134/0x134
kern :warn : [ 12.232803] [<ffffffff815ab7a2>] __platform_driver_probe+0x62/0x110
kern :warn : [ 12.239896] [<ffffffff8205a133>] ? mlxcpld_i2c_probe+0x134/0x134
kern :warn : [ 12.246707] [<ffffffff81ff5896>] ? set_debug_rodata+0x12/0x12
kern :warn : [ 12.253219] [<ffffffff8205a1b3>] mlxcpld_i2c_init+0x80/0x87
kern :warn : [ 12.259560] [<ffffffff8100217d>] do_one_initcall+0x3d/0x150
kern :warn : [ 12.265876] [<ffffffff81ff5896>] ? set_debug_rodata+0x12/0x12
kern :warn : [ 12.272393] [<ffffffff81ff6101>] kernel_init_freeable+0x198/0x225
kern :warn : [ 12.279308] [<ffffffff8192232e>] kernel_init+0xe/0x100
kern :warn : [ 12.285149] [<ffffffff8192fcbf>] ret_from_fork+0x1f/0x40
kern :warn : [ 12.291174] [<ffffffff81922320>] ? rest_init+0x90/0x90
kern :warn : [ 12.297025] ---[ end trace 9f7710331b941587 ]---
kern :err : [ 12.302187] i2c_mlxcpld i2c_mlxcpld: Failed to add i2c_mlxcpld adapter (-16)
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/lkp-tests.git
cd lkp-tests
bin/lkp install job.yaml # job file is attached in this email
bin/lkp run job.yaml
Thanks,
Xiaolong
5 years, 8 months
Re: [LKP] [lkp] [mm, page_alloc] e6cbd7f2ef: pixz.throughput -5.1% regression
by Mel Gorman
On Sun, Aug 28, 2016 at 11:51:20AM +0200, Thorsten Leemhuis wrote:
> Lo! On 08.08.2016 10:29, kernel test robot wrote:
> >
> > FYI, we noticed a -5.1% regression of pixz.throughput due to commit:
> >
> > commit e6cbd7f2efb433d717af72aa8510a9db6f7a7e05 ("mm, page_alloc: remove fair zone allocation policy")
> > https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
> >
> > in testcase: pixz
> > on test machine: 48 threads Ivytown Ivy Bridge-EP with 64G memory
> > with following parameters:
> >
> > nr_threads: 100%
> > cpufreq_governor: performance
>
> Mel, this report made it to the regression list for 4.8, but it seems
> nothing happened after the initial report. Was it discussed (and maybe
> even fixed?) elsewhere? Or was it deemed not important enough? Should I
> drop it for the regression list?
>
Drop it for the moment.
My expectation is that it's a relatively minor hazard. The removal of the
fair zone allocation policy is a shorter path which benefits a number
of workloads but also potentially changes the color of pages used in
microbenchmarks which can have a cache effect. It's on my TODO list to
reproduce this exactly as LKP does but my own preliminary experiments using
pbzip (yes, it's different) on 4 machines showed gains on all 4 machines
so something relatively subtle is going on or it's machine specific.
--
Mel Gorman
SUSE Labs
5 years, 8 months
[ima] 8078f3035b: BUG: spinlock bad magic on CPU#1, swapper/0/1
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/zohar/linux-integrity.git next-restore-kexec
commit 8078f3035b9dc488ed4e896635f491cdd79e9239 ("ima: store the builtin/custom template definitions in a list")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -smp 2 -m 512M
caused below changes:
+----------------+------------+------------+
| | 379c7b5248 | 8078f3035b |
+----------------+------------+------------+
| boot_successes | 0 | 0 |
+----------------+------------+------------+
[ 17.855906] kAFS: Red Hat AFS client v0.1 registering.
[ 17.860556] Key type trusted registered
[ 17.862727] Key type encrypted registered
[ 17.863678] BUG: spinlock bad magic on CPU#1, swapper/0/1
[ 17.864810] lock: template_list+0x0/0x38, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
[ 17.866700] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.8.0-rc1-00027-g8078f30 #1
[ 17.868375] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 17.870267] 0000000000000000 ffff88001ceefdd0 ffffffffa3c29e13 0000000000000000
[ 17.872268] ffffffffa7b29180 ffff88001ceefdf0 ffffffffa35a6547 ffffffffa7b29180
[ 17.874302] 0000000000000003 ffff88001ceefe10 ffffffffa35a658a ffffffffa7b29180
[ 17.876716] Call Trace:
[ 17.877559] [<ffffffffa3c29e13>] dump_stack+0xc5/0x128
[ 17.878578] [<ffffffffa35a6547>] spin_dump+0x9f/0xa4
[ 17.879729] [<ffffffffa35a658a>] spin_bug+0x3e/0x40
[ 17.881509] [<ffffffffa35a66fa>] do_raw_spin_lock+0x5b/0x20c
[ 17.883350] [<ffffffffa6bea897>] ? do_early_param+0xbb/0xbb
[ 17.884465] [<ffffffffa4af45ea>] _raw_spin_lock+0x3a/0x41
[ 17.885514] [<ffffffffa6c4e2fa>] ? ima_init_template_list+0x10/0x5b
[ 17.886662] [<ffffffffa6c4dd75>] ? hash_setup+0x113/0x113
[ 17.887710] [<ffffffffa6c4e2fa>] ima_init_template_list+0x10/0x5b
[ 17.888860] [<ffffffffa6c4dd7f>] init_ima+0xa/0x49
[ 17.890116] [<ffffffffa6beb621>] do_one_initcall+0xaf/0x1b9
[ 17.891212] [<ffffffffa6bea897>] ? do_early_param+0xbb/0xbb
[ 17.892288] [<ffffffffa6beb85c>] kernel_init_freeable+0x131/0x1fb
[ 17.893385] [<ffffffffa4aec274>] kernel_init+0xe/0x16a
[ 17.894442] [<ffffffffa4af55ef>] ret_from_fork+0x1f/0x40
[ 17.895453] [<ffffffffa4aec266>] ? rest_init+0x15d/0x15d
[ 17.924479] ima: No TPM chip found, activating TPM-bypass!
[ 17.926167] evm: HMAC attrs: 0x0
Thanks,
Kernel Test Robot
5 years, 8 months
[ima] ee47739931: BUG: spinlock bad magic on CPU#0, swapper/0/1
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/zohar/linux-integrity.git next-restore-kexec
commit ee47739931a22b314879daedba9299c2834a05e1 ("ima: store the builtin/custom template definitions in a list")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -m 512M
caused below changes:
+----------------+------------+------------+
| | 732ca1f3c9 | ee47739931 |
+----------------+------------+------------+
| boot_successes | 0 | 0 |
+----------------+------------+------------+
[ 6.698532] cryptomgr_probe (168) used greatest stack depth: 14200 bytes left
[ 6.701158] Key type trusted registered
[ 6.702067] Key type encrypted registered
[ 6.702721] BUG: spinlock bad magic on CPU#0, swapper/0/1
[ 6.703564] lock: template_list+0x0/0x38, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
[ 6.704863] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.8.0-rc1-00027-gee47739 #3
[ 6.706003] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 6.720399] 0000000000000000 ffff91fa0025bdc0 ffffffffba7b7b2c 0000000000000000
[ 6.721615] ffffffffbc8ffcd0 ffff91fa0025bde0 ffffffffba572615 ffffffffbc8ffcd0
[ 6.722829] 0000000000000001 ffff91fa0025be00 ffffffffba572645 ffffffffbc8ffcd0
[ 6.724044] Call Trace:
[ 6.724443] [<ffffffffba7b7b2c>] dump_stack+0x85/0xbe
[ 6.725234] [<ffffffffba572615>] spin_dump+0x90/0x95
[ 6.726019] [<ffffffffba572645>] spin_bug+0x2b/0x2d
[ 6.726795] [<ffffffffba57278e>] do_raw_spin_lock+0x45/0x191
[ 6.727689] [<ffffffffbb0cbdbd>] _raw_spin_lock+0x3d/0x41
[ 6.728542] [<ffffffffbbabb5a7>] ? ima_init_template_list+0x18/0x51
[ 6.729534] [<ffffffffbbabb5a7>] ima_init_template_list+0x18/0x51
[ 6.730483] [<ffffffffbbabb155>] ? hash_setup+0xb3/0xb3
[ 6.731296] [<ffffffffbbabb15f>] init_ima+0xa/0x36
[ 6.732057] [<ffffffffbba81198>] do_one_initcall+0x8b/0x153
[ 6.732942] [<ffffffffba538e00>] ? parse_args+0x17e/0x29f
[ 6.733789] [<ffffffffbba8143c>] kernel_init_freeable+0x1dc/0x264
[ 6.734738] [<ffffffffbba8088c>] ? set_debug_rodata+0x12/0x12
[ 6.735631] [<ffffffffbb0c3cc3>] kernel_init+0xe/0xfd
[ 6.736392] [<ffffffffbb0cc90f>] ret_from_fork+0x1f/0x40
[ 6.737190] [<ffffffffbb0c3cb5>] ? rest_init+0x13c/0x13c
[ 6.738170] ima: No TPM chip found, activating TPM-bypass!
[ 6.739101] ------------[ cut here ]------------
[ 6.739867] WARNING: CPU: 0 PID: 1 at init/main.c:790 do_one_initcall+0x12b/0x153
[ 6.741307] initcall init_ima+0x0/0x36 returned with preemption imbalance
[ 6.742385] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.8.0-rc1-00027-gee47739 #3
[ 6.743530] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 6.744870] 0000000000000000 ffff91fa0025bde8 ffffffffba7b7b2c ffff91fa0025be38
[ 6.746084] 0000000000000000 ffff91fa0025be28 ffffffffba518a10 0000031620b97089
[ 6.747308] ffffffffbbabb155 0000000000000001 0000000000000000 0000000000000001
[ 6.748524] Call Trace:
[ 6.748915] [<ffffffffba7b7b2c>] dump_stack+0x85/0xbe
[ 6.749710] [<ffffffffba518a10>] __warn+0xc5/0xe0
[ 6.750455] [<ffffffffbbabb155>] ? hash_setup+0xb3/0xb3
[ 6.751263] [<ffffffffba518a7a>] warn_slowpath_fmt+0x4f/0x51
[ 6.752141] [<ffffffffbbabb12c>] ? hash_setup+0x8a/0xb3
[ 6.752937] [<ffffffffbbabb155>] ? hash_setup+0xb3/0xb3
[ 6.753721] [<ffffffffbbabb155>] ? hash_setup+0xb3/0xb3
[ 6.754505] [<ffffffffbba81238>] do_one_initcall+0x12b/0x153
[ 6.755346] [<ffffffffbba8143c>] kernel_init_freeable+0x1dc/0x264
[ 6.756243] [<ffffffffbba8088c>] ? set_debug_rodata+0x12/0x12
[ 6.757101] [<ffffffffbb0c3cc3>] kernel_init+0xe/0xfd
[ 6.757879] [<ffffffffbb0cc90f>] ret_from_fork+0x1f/0x40
[ 6.758757] [<ffffffffbb0c3cb5>] ? rest_init+0x13c/0x13c
[ 6.759593] ---[ end trace 0a42846a83c9d229 ]---
[ 6.760298] evm: HMAC attrs: 0x1
Thanks,
Kernel Test Robot
5 years, 8 months
[linux] 8acbf38da2: BUG: key ffff88013c9b9e18 not in .data!
by kernel test robot
FYI, we noticed the following commit:
git://git.cmpxchg.org/linux-mmotm.git master
commit 8acbf38da2bcdae9741db330e91ccb4029127af7 ("linux-next")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu host -smp 2 -m 4G
caused below changes:
+----------------+------------+------------+
| | 5748d5502c | 8acbf38da2 |
+----------------+------------+------------+
| boot_successes | 16 | 0 |
+----------------+------------+------------+
[ 19.090214] usbip_core: USB/IP Core v1.0.0
[ 19.092359] vhci_hcd vhci_hcd: USB/IP Virtual Host Controller
[ 19.094776] vhci_hcd vhci_hcd: new USB bus registered, assigned bus number 1
[ 19.096499] BUG: key ffff88013c9b9e18 not in .data!
[ 19.097781] ------------[ cut here ]------------
[ 19.098779] WARNING: CPU: 0 PID: 1 at kernel/locking/lockdep.c:3131 lockdep_init_map+0x11c/0x1c6
[ 19.100964] DEBUG_LOCKS_WARN_ON(1)
[ 19.101624] Modules linked in:
[ 19.102890] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.8.0-rc3-mm1-00165-g8acbf38 #299
[ 19.104728] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 19.106610] 0000000000000000 ffffc90000c57a18 ffffffff8179bb41 ffffc90000c57a68
[ 19.108754] 0000000000000000 ffffc90000c57a58 ffffffff810e60bf 00000c3b00c57ad0
[ 19.111149] ffff88013ca56d90 ffff88013c9b9e18 0000000000000000 0000000000001000
[ 19.113416] Call Trace:
[ 19.114065] [<ffffffff8179bb41>] dump_stack+0x82/0xb8
[ 19.115183] [<ffffffff810e60bf>] __warn+0xc2/0xdd
[ 19.116333] [<ffffffff810e6125>] warn_slowpath_fmt+0x4b/0x53
[ 19.117655] [<ffffffff81123aa8>] lockdep_init_map+0x11c/0x1c6
[ 19.119775] [<ffffffff81294db2>] __kernfs_create_file+0x7a/0xc9
[ 19.122065] [<ffffffff81295593>] sysfs_add_file_mode_ns+0xcf/0x176
[ 19.124166] [<ffffffff81295ff7>] internal_create_group+0x18f/0x268
[ 19.126367] [<ffffffff82689b2b>] ? vhci_urb_dequeue+0x204/0x204
[ 19.128031] [<ffffffff812960e3>] sysfs_create_group+0x13/0x15
[ 19.129171] [<ffffffff826898f0>] vhci_start+0x187/0x1be
[ 19.130319] [<ffffffff825d2fb1>] usb_add_hcd+0x416/0x787
[ 19.131485] [<ffffffff826891b2>] vhci_hcd_probe+0x58/0x7d
[ 19.132697] [<ffffffff81c17ccb>] platform_drv_probe+0x3a/0x7d
[ 19.133975] [<ffffffff81c161bb>] driver_probe_device+0x113/0x25c
[ 19.135184] [<ffffffff81c1643d>] __device_attach_driver+0x85/0x8c
[ 19.136552] [<ffffffff81c163b8>] ? driver_allows_async_probing+0x2e/0x2e
[ 19.137965] [<ffffffff81c145f9>] bus_for_each_drv+0x7b/0x8a
[ 19.139157] [<ffffffff81c1601c>] __device_attach+0x93/0xf2
[ 19.140233] [<ffffffff81c1659c>] device_initial_probe+0x13/0x15
[ 19.141488] [<ffffffff81c1555a>] bus_probe_device+0x33/0x9e
[ 19.142834] [<ffffffff81c139c6>] device_add+0x405/0x505
[ 19.143907] [<ffffffff846327c5>] ? set_debug_rodata+0x12/0x12
[ 19.145344] [<ffffffff81c17b27>] platform_device_add+0x141/0x1a1
[ 19.146647] [<ffffffff846327c5>] ? set_debug_rodata+0x12/0x12
[ 19.147873] [<ffffffff81c1830a>] platform_device_register_full+0xb3/0x109
[ 19.149136] [<ffffffff846c2b4c>] vhci_hcd_init+0xb9/0x118
[ 19.150311] [<ffffffff846c2a93>] ? usbip_core_init+0x17/0x17
[ 19.151445] [<ffffffff810021b0>] do_one_initcall+0x90/0x11f
[ 19.152786] [<ffffffff846327c5>] ? set_debug_rodata+0x12/0x12
[ 19.154101] [<ffffffff84633146>] kernel_init_freeable+0x1c6/0x253
[ 19.155353] [<ffffffff82f35704>] ? rest_init+0x13b/0x13b
[ 19.156488] [<ffffffff82f35712>] kernel_init+0xe/0xf5
[ 19.157719] [<ffffffff82f41a2a>] ret_from_fork+0x2a/0x40
[ 19.158827] ---[ end trace ca0214f9e3cac3d2 ]---
[ 19.160210] vhci_hcd: created sysfs vhci_hcd
Thanks,
Kernel Test Robot
5 years, 8 months
[ima] 05af459445: WARNING: CPU: 0 PID: 1 at init/main.c:790 do_one_initcall+0x13f/0x150
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/zohar/linux-integrity.git next-restore-kexec
commit 05af45944548af658bd34885e70255aeb3156af2 ("ima: store the builtin/custom template definitions in a list")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu kvm64,+ssse3 -smp 2 -m 8G
caused below changes:
+----------------+------------+------------+
| | 1cc4066e79 | 05af459445 |
+----------------+------------+------------+
| boot_successes | 2 | 0 |
+----------------+------------+------------+
[ 6.848816] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x209746ac25a, max_idle_ns: 440795298337 ns
[ 6.852984] ima: No TPM chip found, activating TPM-bypass!
[ 6.855137] ------------[ cut here ]------------
[ 6.857068] WARNING: CPU: 0 PID: 1 at init/main.c:790 do_one_initcall+0x13f/0x150
[ 6.860666] initcall init_ima+0x0/0x35 returned with preemption imbalance
[ 6.863085] Modules linked in:
[ 6.864802] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.8.0-rc1-00027-g05af459 #5
[ 6.868110] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 6.871710] 0000000000000000 ffff88022a16bd78 ffffffff8144c479 ffff88022a16bdc8
[ 6.875448] 0000000000000000 ffff88022a16bdb8 ffffffff8107e6cb 0000031611fa5240
[ 6.879205] 0000000000000000 ffffffff8203e2ae 0000000000000000 ffffffff81ff589b
[ 6.883065] Call Trace:
[ 6.884506] [<ffffffff8144c479>] dump_stack+0x63/0x8a
[ 6.886492] [<ffffffff8107e6cb>] __warn+0xcb/0xf0
[ 6.888410] [<ffffffff8203e2ae>] ? hash_setup+0xb3/0xb3
[ 6.890521] [<ffffffff81ff589b>] ? set_debug_rodata+0x12/0x12
[ 6.892720] [<ffffffff8107e73f>] warn_slowpath_fmt+0x4f/0x60
[ 6.894883] [<ffffffff8203e285>] ? hash_setup+0x8a/0xb3
[ 6.896956] [<ffffffff8203e2ae>] ? hash_setup+0xb3/0xb3
[ 6.899018] [<ffffffff8203e2ae>] ? hash_setup+0xb3/0xb3
[ 6.901115] [<ffffffff8100227f>] do_one_initcall+0x13f/0x150
[ 6.903292] [<ffffffff81ff589b>] ? set_debug_rodata+0x12/0x12
[ 6.905466] [<ffffffff81ff6106>] kernel_init_freeable+0x198/0x225
[ 6.907734] [<ffffffff819221fe>] kernel_init+0xe/0x100
[ 6.909800] [<ffffffff8192fbbf>] ret_from_fork+0x1f/0x40
[ 6.911909] [<ffffffff819221f0>] ? rest_init+0x90/0x90
[ 6.913971] ---[ end trace c327d0ded2ed29ff ]---
[ 6.915923] evm: HMAC attrs: 0x1
Thanks,
Kernel Test Robot
5 years, 8 months
[locking/mutex] f8e9505c9e: WARNING: CPU: 0 PID: 0 at lib/locking-selftest.c:1152 ww_test_fail_acquire+0xa1/0x149
by kernel test robot
FYI, we noticed the following commit:
https://git.kernel.org/pub/scm/linux/kernel/git/peterz/queue.git locking/rfc
commit f8e9505c9eb46735abb6b6fb5428e63a51c84946 ("locking/mutex: Add lock handoff to avoid starvation")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu kvm64,+ssse3 -smp 2 -m 8G
caused below changes:
+----------------+------------+------------+
| | 37c96f6838 | f8e9505c9e |
+----------------+------------+------------+
| boot_successes | 60 | 0 |
+----------------+------------+------------+
[ 0.000000] ---------------------
[ 0.000000] ww api failures:
[ 0.000000] ------------[ cut here ]------------
[ 0.000000] WARNING: CPU: 0 PID: 0 at lib/locking-selftest.c:1152 ww_test_fail_acquire+0xa1/0x149
[ 0.000000] Modules linked in:
[ 0.000000] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.8.0-rc2-00250-gf8e9505 #1
[ 0.000000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 0.000000] 0000000000000000 ffffffff84003ea8 ffffffff8178dfd9 0000000000000000
[ 0.000000] 0000000000000000 ffffffff84003ee8 ffffffff810e5d76 0000048084003e70
[ 0.000000] ffffffff856e0120 0000000000000001 0000000000000010 ffffffff817ae7f0
[ 0.000000] Call Trace:
[ 0.000000] [<ffffffff8178dfd9>] dump_stack+0x82/0xb8
[ 0.000000] [<ffffffff810e5d76>] __warn+0xc2/0xdd
[ 0.000000] [<ffffffff817ae7f0>] ? ww_test_context_lock_after_done+0x23/0x23
[ 0.000000] [<ffffffff810e5e4d>] warn_slowpath_null+0x1d/0x1f
[ 0.000000] [<ffffffff817ae891>] ww_test_fail_acquire+0xa1/0x149
[ 0.000000] [<ffffffff817c42e1>] dotest+0x42/0x5a2
[ 0.000000] [<ffffffff817b0edd>] locking_selftest+0x1910/0x1d3b
[ 0.000000] [<ffffffff84633e04>] start_kernel+0x2ec/0x43d
[ 0.000000] [<ffffffff84633120>] ? early_idt_handler_array+0x120/0x120
[ 0.000000] [<ffffffff846332d6>] x86_64_start_reservations+0x2a/0x2c
[ 0.000000] [<ffffffff8463340b>] x86_64_start_kernel+0x133/0x142
[ 0.000000] ---[ end trace 0000000000000000 ]---
[ 0.000000] ------------[ cut here ]------------
Thanks,
Kernel Test Robot
5 years, 8 months
[lkp] [proc, meminfo] dd3b422c11: stderr.Signal#(FPE)caught_by_ps(procps-ng_version#)
by kernel test robot
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Michal-Hocko/fs-proc-optimize-smaps-output-formatting/20160819-181512
commit dd3b422c110260cf16491b8c5baad029c8a762c6 ("proc, meminfo: abstract show_val_kb")
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap -smp 2 -m 1G
caused below changes:
user :notice: [ +6.170898] 20 Aug 04:48:28 ntpdate[337]: step time server 192.168.1.1 offset 5.245972 sec
user :notice: [ +0.009497] /lkp/lkp/src/bin/run-lkp
user :notice: [ +0.022923] RESULT_ROOT=/result/boot/1/vm-kbuild-1G/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-6/dd3b422c110260cf16491
b8c5baad029c8a762c6/0
user :notice: [ +0.023769] job=/lkp/scheduled/vm-kbuild-1G-4/boot-1-debian-x86_64-2015-02-07.cgz-dd3b422c110260cf16491b8c5baad029c8a762
c6-20160820-77296-8ie4hi-0.yaml
user :notice: [ +0.449549] run-job /lkp/scheduled/vm-kbuild-1G-4/boot-1-debian-x86_64-2015-02-07.cgz-dd3b422c110260cf16491b8c5baad029c8
a762c6-20160820-77296-8ie4hi-0.yaml
user :err : [ +5.618148] Signal 8 (FPE) caught by ps (procps-ng version 3.3.10).
user :err : [ +0.001869] ps:display.c:66: please report this bug
user :err : [ +0.002004] Floating point exception
FYI, raw QEMU command line is:
qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap -kernel /pkg/linux/x86_64-rhel/gcc-6/dd3b422c110260cf16491b8c5baad029c8a762c6/vmlinuz-4.8.0-rc2-next-20160819-00001-gdd3b422 -append 'ip=::::vm-kbuild-1G-4::dhcp root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-1G-4/boot-1-debian-x86_64-2015-02-07.cgz-dd3b422c110260cf16491b8c5baad029c8a762c6-20160820-77296-8ie4hi-0.yaml ARCH=x86_64 kconfig=x86_64-rhel branch=linux-devel/devel-catchup-201608192016 commit=dd3b422c110260cf16491b8c5baad029c8a762c6 BOOT_IMAGE=/pkg/linux/x86_64-rhel/gcc-6/dd3b422c110260cf16491b8c5baad029c8a762c6/vmlinuz-4.8.0-rc2-next-20160819-00001-gdd3b422 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-kbuild-1G/debian-x86_64-2015-02-07.cgz/x86_64-rhel/gcc-6/dd3b422c110260cf16491b8c5baad029c8a762c6/0 LKP_SERVER=inn debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 systemd.log_level=err ignore_loglevel earlyprintk=ttyS0,115200 console=ttyS0,115200 console=tty0 vga=normal rw' -initrd /fs/sdf1/initrd-vm-kbuild-1G-4 -m 1024 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0,hostfwd=tcp::23003-:22 -boot order=nc -no-reboot -watchdog i6300esb -watchdog-action debug -rtc base=localtime -device virtio-scsi-pci,id=scsi0 -drive file=/fs/sdf1/disk0-vm-kbuild-1G-4,if=none,id=hd0,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd0,scsi-id=1,lun=0 -drive file=/fs/sdf1/disk1-vm-kbuild-1G-4,if=none,id=hd1,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd1,scsi-id=1,lun=1 -drive file=/fs/sdf1/disk2-vm-kbuild-1G-4,if=none,id=hd2,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd2,scsi-id=1,lun=2 -drive file=/fs/sdf1/disk3-vm-kbuild-1G-4,if=none,id=hd3,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd3,scsi-id=1,lun=3 -drive file=/fs/sdf1/disk4-vm-kbuild-1G-4,if=none,id=hd4,media=disk,aio=native,cache=none -device scsi-hd,bus=scsi0.0,drive=hd4,scsi-id=1,lun=4 -pidfile /dev/shm/kboot/pid-vm-kbuild-1G-4 -serial file:/dev/shm/kboot/serial-vm-kbuild-1G-4 -daemonize -display none -monitor null
Thanks,
Xiaolong
5 years, 9 months
[lkp] [mm, THP, swap] 26174d6789: [No primary change] [vm-scalability] meminfo.SwapCached -35.2%
by kernel test robot
FYI, we noticed ameminfo.SwapCached -35.2% due to commit:
commit 26174d6789c3dc1bd6388a5ce94a23283c2a2f00 ("mm, THP, swap: Delay splitting THP during swap out")
git://bee.sh.intel.com/git/yhuang/linux.git thp_swap
in testcase: vm-scalability
on test machine: 72 threads Haswell-EP with 128G memory
with following parameters:
thp_enabled: always
thp_defrag: never
nr_task: 4
nr_ssd: 1
test: swap-w-seq
cpufreq_governor: performance
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.
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone git://git.kernel.org/pub/scm/linux/kernel/git/wfg/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/nr_ssd/nr_task/rootfs/tbox_group/test/testcase/thp_defrag/thp_enabled:
gcc-6/performance/x86_64-rhel/1/4/debian-x86_64-2015-02-07.cgz/lkp-hsw-ep4/swap-w-seq/vm-scalability/never/always
commit:
aab336c885 ("mm, THP, swap: Support to split THP in swap cache")
26174d6789 ("mm, THP, swap: Delay splitting THP during swap out")
aab336c88590b809 26174d6789c3dc1bd6388a5ce9
---------------- --------------------------
%stddev %change %stddev
\ | \
2031480 ± 0% +2.6% 2084316 ± 0% vm-scalability.throughput
443.56 ± 0% -2.2% 433.84 ± 0% vm-scalability.time.elapsed_time
443.56 ± 0% -2.2% 433.84 ± 0% vm-scalability.time.elapsed_time.max
39526382 ± 2% +7.2% 42382806 ± 2% vm-scalability.time.maximum_resident_set_size
395.80 ± 0% -2.1% 387.50 ± 0% vm-scalability.time.percent_of_cpu_this_job_got
1581 ± 0% -5.1% 1501 ± 0% vm-scalability.time.system_time
177.13 ± 0% +2.6% 181.67 ± 0% vm-scalability.time.user_time
53095 ± 5% +38.0% 73253 ± 2% vm-scalability.time.voluntary_context_switches
0.11 ± 5% +334.6% 0.47 ± 20% turbostat.CPU%c3
991292 ± 2% -35.2% 641889 ± 3% meminfo.SwapCached
1054 ± 21% +5988.5% 64179 ± 26% meminfo.Writeback
11479592 ± 11% -33.3% 7659428 ± 27% numa-numastat.node0.numa_miss
11477000 ± 11% -33.3% 7660452 ± 27% numa-numastat.node1.numa_foreign
1247586 ± 0% +2.3% 1276486 ± 0% vmstat.io.bo
1247581 ± 0% +2.3% 1276481 ± 0% vmstat.swap.so
4500 ± 3% +12.9% 5081 ± 3% vmstat.system.cs
285511 ± 0% +1.2% 288951 ± 0% vmstat.system.in
731184 ± 2% -28.2% 525110 ± 3% numa-meminfo.node0.FilePages
355.80 ± 26% +7007.9% 25289 ± 29% numa-meminfo.node0.Writeback
5799314 ± 3% -13.8% 4996661 ± 5% numa-meminfo.node1.AnonHugePages
767041 ± 1% -19.5% 617160 ± 1% numa-meminfo.node1.FilePages
760.90 ± 26% +5257.6% 40766 ± 23% numa-meminfo.node1.Writeback
48093110 ± 32% -55.4% 21457658 ± 64% proc-vmstat.compact_migrate_scanned
373419 ± 1% -23.4% 285946 ± 1% proc-vmstat.nr_file_pages
387.50 ± 7% -20.3% 309.00 ± 8% proc-vmstat.nr_isolated_anon
259.10 ± 21% +6100.1% 16064 ± 25% proc-vmstat.nr_writeback
260.30 ± 21% +6071.8% 16065 ± 25% proc-vmstat.nr_zone_write_pending
95036977 ± 1% +25.9% 1.197e+08 ± 1% proc-vmstat.pgrotated
5684991 ± 12% +77.6% 10098074 ± 6% cpuidle.C1-HSW.time
140366 ± 5% +35.7% 190484 ± 8% cpuidle.C1-HSW.usage
16468301 ± 6% +149.2% 41039481 ± 12% cpuidle.C1E-HSW.time
140141 ± 4% +81.2% 253971 ± 9% cpuidle.C1E-HSW.usage
82728198 ± 3% +149.2% 2.061e+08 ± 15% cpuidle.C3-HSW.time
289413 ± 4% +104.3% 591337 ± 12% cpuidle.C3-HSW.usage
5.43e+08 ± 6% +31.6% 7.147e+08 ± 15% cpuidle.POLL.time
3639 ± 5% +106.7% 7522 ± 8% cpuidle.POLL.usage
4048 ± 1% +28.4% 5198 ± 13% slabinfo.kmalloc-1024.active_objs
4131 ± 1% +26.3% 5217 ± 13% slabinfo.kmalloc-1024.num_objs
5487 ± 2% +28.3% 7038 ± 2% slabinfo.kmalloc-2048.active_objs
5542 ± 2% +28.8% 7138 ± 2% slabinfo.kmalloc-2048.num_objs
17739 ± 3% +88.2% 33392 ± 12% slabinfo.kmalloc-256.active_objs
449.20 ± 2% +163.2% 1182 ± 16% slabinfo.kmalloc-256.active_slabs
17969 ± 3% +91.7% 34451 ± 12% slabinfo.kmalloc-256.num_objs
449.20 ± 2% +163.2% 1182 ± 16% slabinfo.kmalloc-256.num_slabs
183104 ± 2% -28.3% 131262 ± 3% numa-vmstat.node0.nr_file_pages
86.70 ± 22% +7309.7% 6424 ± 29% numa-vmstat.node0.nr_writeback
86.00 ± 22% +7369.4% 6423 ± 29% numa-vmstat.node0.nr_zone_write_pending
7638209 ± 10% -32.9% 5121808 ± 18% numa-vmstat.node0.numa_miss
2856 ± 3% -13.9% 2458 ± 5% numa-vmstat.node1.nr_anon_transparent_hugepages
191915 ± 1% -19.8% 153939 ± 1% numa-vmstat.node1.nr_file_pages
186.70 ± 23% +5235.8% 9961 ± 23% numa-vmstat.node1.nr_writeback
188.00 ± 23% +5199.3% 9962 ± 23% numa-vmstat.node1.nr_zone_write_pending
7596213 ± 10% -32.9% 5095994 ± 18% numa-vmstat.node1.numa_foreign
6.168e+09 ± 2% -5.2% 5.849e+09 ± 2% perf-stat.branch-misses
29.35 ± 1% -7.1% 27.27 ± 3% perf-stat.cache-miss-rate%
1.33e+10 ± 4% -10.3% 1.193e+10 ± 4% perf-stat.cache-misses
1994080 ± 3% +10.4% 2201984 ± 3% perf-stat.context-switches
1.426e+13 ± 3% -6.5% 1.334e+13 ± 2% perf-stat.cpu-cycles
33081 ± 5% +29.1% 42715 ± 3% perf-stat.cpu-migrations
0.43 ± 0% +2.4% 0.44 ± 1% perf-stat.ipc
2.522e+09 ± 0% -6.5% 2.357e+09 ± 1% perf-stat.node-store-misses
1.531e+09 ± 1% -8.6% 1.399e+09 ± 3% perf-stat.node-stores
10.65 ± 30% +354.4% 48.40 ± 37% sched_debug.cpu.clock.stddev
10.65 ± 30% +354.4% 48.40 ± 37% sched_debug.cpu.clock_task.stddev
0.00 ± 9% +111.6% 0.00 ± 30% sched_debug.cpu.next_balance.stddev
16027 ± 3% +16.6% 18695 ± 2% sched_debug.cpu.nr_switches.avg
1615 ± 7% +41.0% 2277 ± 8% sched_debug.cpu.nr_switches.min
15521 ± 6% +14.6% 17793 ± 7% sched_debug.cpu.nr_switches.stddev
9.21 ± 12% +23.4% 11.36 ± 9% sched_debug.cpu.nr_uninterruptible.stddev
16032 ± 3% +17.5% 18838 ± 2% sched_debug.cpu.sched_count.avg
1329 ± 8% +47.0% 1955 ± 10% sched_debug.cpu.sched_count.min
4057 ± 2% +22.8% 4982 ± 2% sched_debug.cpu.sched_goidle.avg
599.96 ± 8% +52.2% 912.88 ± 10% sched_debug.cpu.sched_goidle.min
7651 ± 3% +19.9% 9175 ± 2% sched_debug.cpu.ttwu_count.avg
32451 ± 15% +30.5% 42349 ± 14% sched_debug.cpu.ttwu_count.max
7932 ± 6% +24.2% 9849 ± 7% sched_debug.cpu.ttwu_count.stddev
4460 ± 4% +15.1% 5135 ± 4% sched_debug.cpu.ttwu_local.avg
0.00 ± 23% -72.8% 0.00 ±116% sched_debug.rt_rq:/.rt_time.min
0.00 ± -1% +Inf% 5086 ±104% latency_stats.avg.bt_get.blk_mq_get_tag.__blk_mq_alloc_request.blk_mq_map_request.blk_mq_make_request.generic_make_request.submit_bio.swap_readpage.read_swap_cache_async.swapin_readahead.do_swap_page.handle_mm_fault
27185 ± 20% +153.5% 68917 ± 95% latency_stats.avg.max
1790 ± 49% +1945.9% 36634 ± 99% latency_stats.avg.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.copy_fpstate_to_sigframe.do_signal.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
1158 ±101% +2444.8% 29481 ±208% latency_stats.avg.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.do_signal.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
1080 ± 24% +461.3% 6062 ± 43% latency_stats.avg.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.ep_scan_ready_list.ep_poll.SyS_epoll_wait.entry_SYSCALL_64_fastpath
1769 ± 33% +911.0% 17890 ±141% latency_stats.avg.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.proc_reg_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 35709 ± 21% latency_stats.max.bt_get.blk_mq_get_tag.__blk_mq_alloc_request.blk_mq_map_request.blk_mq_make_request.generic_make_request.submit_bio.__swap_writepage.swap_writepage.pageout.shrink_page_list.shrink_inactive_list
0.00 ± -1% +Inf% 5967 ±103% latency_stats.max.bt_get.blk_mq_get_tag.__blk_mq_alloc_request.blk_mq_map_request.blk_mq_make_request.generic_make_request.submit_bio.swap_readpage.read_swap_cache_async.swapin_readahead.do_swap_page.handle_mm_fault
28171 ± 17% +2678.1% 782639 ± 13% latency_stats.max.max
8546 ± 69% +1241.8% 114672 ±151% latency_stats.max.pipe_write.__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
14270 ± 36% +5329.5% 774840 ± 13% latency_stats.max.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault
1604 ± 44% +5080.7% 83113 ±261% latency_stats.max.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.SyS_poll.entry_SYSCALL_64_fastpath
4446 ± 51% +3474.4% 158934 ±127% latency_stats.max.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.copy_fpstate_to_sigframe.do_signal.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
7211 ± 85% +1802.0% 137155 ±122% latency_stats.max.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.copy_page_to_iter.pipe_read.__vfs_read.vfs_read.SyS_read
3005 ±130% +3235.7% 100252 ±246% latency_stats.max.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.do_signal.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
2041 ±108% +4367.1% 91173 ±209% latency_stats.max.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.do_wait.SyS_wait4.entry_SYSCALL_64_fastpath
3891 ± 34% +577.7% 26372 ± 59% latency_stats.max.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.ep_scan_ready_list.ep_poll.SyS_epoll_wait.entry_SYSCALL_64_fastpath
3926 ±104% +390.9% 19276 ±107% latency_stats.max.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
4526 ± 39% +2118.2% 100395 ±203% latency_stats.max.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.proc_reg_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath
0.00 ± -1% +Inf% 33293129 ± 33% latency_stats.sum.bt_get.blk_mq_get_tag.__blk_mq_alloc_request.blk_mq_map_request.blk_mq_make_request.generic_make_request.submit_bio.__swap_writepage.swap_writepage.pageout.shrink_page_list.shrink_inactive_list
0.00 ± -1% +Inf% 6759 ±109% latency_stats.sum.bt_get.blk_mq_get_tag.__blk_mq_alloc_request.blk_mq_map_request.blk_mq_make_request.generic_make_request.submit_bio.swap_readpage.read_swap_cache_async.swapin_readahead.do_swap_page.handle_mm_fault
80122 ± 7% -100.0% 0.00 ± -1% latency_stats.sum.call_rwsem_down_write_failed.split_huge_page_to_list.add_to_swap.shrink_page_list.shrink_inactive_list.shrink_node_memcg.shrink_node.do_try_to_free_pages.try_to_free_pages.__alloc_pages_slowpath.__alloc_pages_nodemask.alloc_pages_vma
0.00 ± -1% +Inf% 47089 ± 18% latency_stats.sum.call_rwsem_down_write_failed.split_huge_page_to_list.add_to_swap_trans_huge.add_to_swap.shrink_page_list.shrink_inactive_list.shrink_node_memcg.shrink_node.do_try_to_free_pages.try_to_free_pages.__alloc_pages_slowpath.__alloc_pages_nodemask
7418224 ± 0% +350.4% 33414142 ± 32% latency_stats.sum.max
507404 ± 46% +289.4% 1975749 ± 35% latency_stats.sum.mempool_alloc.bio_alloc_bioset.get_swap_bio.__swap_writepage.swap_writepage.pageout.shrink_page_list.shrink_inactive_list.shrink_node_memcg.shrink_node.do_try_to_free_pages.try_to_free_pages
61610 ± 39% +296.0% 243958 ± 99% latency_stats.sum.pipe_write.__vfs_write.vfs_write.SyS_write.entry_SYSCALL_64_fastpath
3000501 ± 9% +610.6% 21321268 ± 16% latency_stats.sum.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault
3094 ± 55% +2711.2% 86998 ±252% latency_stats.sum.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.SyS_poll.entry_SYSCALL_64_fastpath
12531 ± 67% +1453.3% 194660 ± 99% latency_stats.sum.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.copy_fpstate_to_sigframe.do_signal.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
84876 ± 27% +410.0% 432833 ± 67% latency_stats.sum.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.copy_page_to_iter.pipe_read.__vfs_read.vfs_read.SyS_read
4701 ±132% +2202.0% 108229 ±229% latency_stats.sum.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.do_signal.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
3446 ± 71% +2710.2% 96854 ±204% latency_stats.sum.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.do_wait.SyS_wait4.entry_SYSCALL_64_fastpath
10141 ± 31% +479.5% 58768 ± 44% latency_stats.sum.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.ep_scan_ready_list.ep_poll.SyS_epoll_wait.entry_SYSCALL_64_fastpath
7684 ± 96% +271.0% 28511 ±102% latency_stats.sum.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.exit_to_usermode_loop.syscall_return_slowpath.entry_SYSCALL_64_fastpath
10759 ± 39% +1242.8% 144482 ±140% latency_stats.sum.wait_on_page_bit_killable.__lock_page_or_retry.do_swap_page.handle_mm_fault.__do_page_fault.do_page_fault.page_fault.proc_reg_read.__vfs_read.vfs_read.SyS_read.entry_SYSCALL_64_fastpath
Thanks,
Xiaolong
5 years, 9 months