[jump_label] b8efb810ab: leaking-addresses.proc..data.unlikely.
by kernel test robot
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: b8efb810ab1497958e1338a0d7a824bd2d638cfe ("[PATCH 2/2] jump_label: refine placement of static_keys")
url: https://github.com/0day-ci/linux/commits/Eric-Dumazet/jump_label-add-__st...
base: https://git.kernel.org/cgit/linux/kernel/git/herbert/cryptodev-2.6.git master
in testcase: leaking-addresses
version: leaking-addresses-x86_64-cf2a85e-1_20211110
with following parameters:
ucode: 0x28
on test machine: 8 threads 1 sockets Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz with 16G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
Total number of results from scan (incl dmesg): 156275
dmesg output:
[ 1.860342] mapped IOAPIC to ffffffffff5fb000 (fec00000)
Results squashed by filename (excl dmesg). Displaying [<number of results> <filename>], <example result>
...
[4 .data.unlikely] 0xffffffffc04bb1c0 <--- the issue only exists in this commit
[29 .text.unlikely] 0xffffffffc00bac5c <--- this was also observed in parent commit
...
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
6 months
[fs] a0918006f9: netperf.Throughput_tps -11.6% regression
by kernel test robot
Greeting,
FYI, we noticed a -11.6% regression of netperf.Throughput_tps due to commit:
commit: a0918006f9284b77397ae4f163f055c3e0f987b2 ("[PATCH v15 1/3] fs: Add trusted_for(2) syscall implementation and related sysctl")
url: https://github.com/0day-ci/linux/commits/Micka-l-Sala-n/Add-trusted_for-2...
patch link: https://lore.kernel.org/kernel-hardening/20211012192410.2356090-2-mic@dig...
in testcase: netperf
on test machine: 192 threads 4 sockets Intel(R) Xeon(R) Platinum 9242 CPU @ 2.30GHz with 192G memory
with following parameters:
ip: ipv4
runtime: 300s
nr_threads: 16
cluster: cs-localhost
test: TCP_CRR
cpufreq_governor: performance
ucode: 0x5003006
test-description: Netperf is a benchmark that can be use to measure various aspect of networking performance.
test-url: http://www.netperf.org/netperf/
please be noted we made out some further analysis/tests, as Fengwei mentioned:
==============================================================================
Here is my investigation result of this regression:
If I add patch to make sure the kernel function address and data address is
almost same even with this patch, there is almost no performance delta(0.1%)
w/o the patch.
And if I only make sure function address same w/o the patch, the performance
delta is about 5.1%.
So suppose this regression is triggered by different function and data address.
We don't know why the different address could bring such kind of regression yet
===============================================================================
we also tested on other platforms.
on a Cooper Lake (Intel(R) Xeon(R) Gold 5318H CPU @ 2.50GHz with 128G memory),
we also observed regression but the gap is smaller:
=========================================================================================
cluster/compiler/cpufreq_governor/ip/kconfig/nr_threads/rootfs/runtime/tbox_group/test/testcase/ucode:
cs-localhost/gcc-9/performance/ipv4/x86_64-rhel-8.3/16/debian-10.4-x86_64-20200603.cgz/300s/lkp-cpl-4sp1/TCP_CRR/netperf/0x700001e
commit:
v5.15-rc4
a0918006f9284b77397ae4f163f055c3e0f987b2
v5.15-rc4 a0918006f9284b77397ae4f163f
---------------- ---------------------------
%stddev %change %stddev
\ | \
333492 -5.7% 314346 ± 2% netperf.Throughput_total_tps
20843 -4.5% 19896 netperf.Throughput_tps
but no regression on a 96 threads 2 sockets Ice Lake with 256G memory:
=========================================================================================
cluster/compiler/cpufreq_governor/ip/kconfig/nr_threads/rootfs/runtime/tbox_group/test/testcase/ucode:
cs-localhost/gcc-9/performance/ipv4/x86_64-rhel-8.3/16/debian-10.4-x86_64-20200603.cgz/300s/lkp-icl-2sp1/TCP_CRR/netperf/0xb000280
commit:
v5.15-rc4
a0918006f9284b77397ae4f163f055c3e0f987b2
v5.15-rc4 a0918006f9284b77397ae4f163f
---------------- ---------------------------
%stddev %change %stddev
\ | \
555600 -0.1% 555305 netperf.Throughput_total_tps
34725 -0.1% 34706 netperf.Throughput_tps
Fengwei also helped review these results and commented:
I suppose these three CPUs have different cache policy. It also could be
related with netperf throughput testing.
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
Details are as below:
-------------------------------------------------------------------------------------------------->
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
=========================================================================================
cluster/compiler/cpufreq_governor/ip/kconfig/nr_threads/rootfs/runtime/tbox_group/test/testcase/ucode:
cs-localhost/gcc-9/performance/ipv4/x86_64-rhel-8.3/16/debian-10.4-x86_64-20200603.cgz/300s/lkp-csl-2ap3/TCP_CRR/netperf/0x5003006
commit:
v5.15-rc4
a0918006f9 ("fs: Add trusted_for(2) syscall implementation and related sysctl")
v5.15-rc4 a0918006f9284b77397ae4f163f
---------------- ---------------------------
%stddev %change %stddev
\ | \
354692 -11.6% 313620 netperf.Throughput_total_tps
22168 -11.6% 19601 netperf.Throughput_tps
2.075e+08 -11.6% 1.834e+08 netperf.time.voluntary_context_switches
1.064e+08 -11.6% 94086163 netperf.workload
0.27 ± 35% -0.1 0.22 ± 2% mpstat.cpu.all.usr%
2207583 -6.3% 2068413 vmstat.system.cs
3029480 ± 6% -23.3% 2324079 ± 7% interrupts.CAL:Function_call_interrupts
13768 ± 25% -35.6% 8872 ± 23% interrupts.CPU30.CAL:Function_call_interrupts
2014617 ± 16% -26.3% 1485200 ± 24% softirqs.CPU180.NET_RX
3.268e+08 -12.1% 2.874e+08 softirqs.NET_RX
287881 ± 2% +24.6% 358692 softirqs.TIMER
3207001 -9.6% 2899010 perf-sched.wait_and_delay.count.schedule_timeout.inet_csk_accept.inet_accept.do_accept
0.01 ± 15% +67.1% 0.01 ± 9% perf-sched.wait_time.avg.ms.preempt_schedule_common.__cond_resched.__release_sock.release_sock.sk_wait_data
0.02 ± 2% +23.3% 0.03 ± 21% perf-sched.wait_time.avg.ms.preempt_schedule_common.__cond_resched.aa_sk_perm.security_socket_accept.do_accept
0.01 +20.0% 0.01 perf-sched.wait_time.avg.ms.schedule_timeout.wait_woken.sk_wait_data.tcp_recvmsg_locked
63320 ± 2% -10.6% 56615 ± 2% slabinfo.sock_inode_cache.active_objs
1626 ± 2% -10.6% 1454 ± 2% slabinfo.sock_inode_cache.active_slabs
63445 ± 2% -10.6% 56722 ± 2% slabinfo.sock_inode_cache.num_objs
1626 ± 2% -10.6% 1454 ± 2% slabinfo.sock_inode_cache.num_slabs
49195 -3.2% 47624 proc-vmstat.nr_slab_reclaimable
4278441 -6.6% 3996109 proc-vmstat.numa_hit
4052317 ± 2% -7.4% 3751341 proc-vmstat.numa_local
4285136 -6.5% 4006356 proc-vmstat.pgalloc_normal
1704913 -11.4% 1511123 proc-vmstat.pgfree
9.382e+09 -10.1% 8.438e+09 perf-stat.i.branch-instructions
1.391e+08 -10.0% 1.252e+08 perf-stat.i.branch-misses
13.98 +2.2 16.20 perf-stat.i.cache-miss-rate%
87082775 +14.0% 99273064 perf-stat.i.cache-misses
2231661 -6.4% 2088571 perf-stat.i.context-switches
1.65 +8.6% 1.79 perf-stat.i.cpi
7.603e+10 -2.1% 7.441e+10 perf-stat.i.cpu-cycles
907.53 ± 2% -13.0% 789.92 ± 2% perf-stat.i.cycles-between-cache-misses
920324 ± 19% -20.3% 733572 ± 5% perf-stat.i.dTLB-load-misses
1.417e+10 -10.3% 1.271e+10 perf-stat.i.dTLB-loads
182445 ± 16% -57.6% 77419 ± 9% perf-stat.i.dTLB-store-misses
8.254e+09 -10.3% 7.403e+09 perf-stat.i.dTLB-stores
88.23 -1.7 86.52 perf-stat.i.iTLB-load-miss-rate%
96633753 -11.0% 85983323 perf-stat.i.iTLB-load-misses
12277057 +4.0% 12766535 perf-stat.i.iTLB-loads
4.741e+10 -10.2% 4.259e+10 perf-stat.i.instructions
0.62 -8.2% 0.57 perf-stat.i.ipc
0.40 -2.1% 0.39 perf-stat.i.metric.GHz
168.88 -10.1% 151.87 perf-stat.i.metric.M/sec
16134360 ± 2% +15.0% 18550862 perf-stat.i.node-load-misses
1576525 ± 2% +10.0% 1734370 ± 2% perf-stat.i.node-loads
10027868 -11.5% 8871598 perf-stat.i.node-store-misses
386034 ± 3% -16.0% 324290 ± 7% perf-stat.i.node-stores
13.15 +9.2% 14.36 perf-stat.overall.MPKI
13.97 +2.3 16.23 perf-stat.overall.cache-miss-rate%
1.60 +8.9% 1.75 perf-stat.overall.cpi
873.29 -14.2% 749.60 perf-stat.overall.cycles-between-cache-misses
0.00 ± 15% -0.0 0.00 ± 9% perf-stat.overall.dTLB-store-miss-rate%
88.73 -1.7 87.07 perf-stat.overall.iTLB-load-miss-rate%
0.62 -8.2% 0.57 perf-stat.overall.ipc
135778 +1.7% 138069 perf-stat.overall.path-length
9.351e+09 -10.1% 8.41e+09 perf-stat.ps.branch-instructions
1.387e+08 -10.0% 1.248e+08 perf-stat.ps.branch-misses
86797490 +14.0% 98949207 perf-stat.ps.cache-misses
2224197 -6.4% 2081616 perf-stat.ps.context-switches
7.578e+10 -2.1% 7.416e+10 perf-stat.ps.cpu-cycles
917495 ± 19% -20.3% 731365 ± 5% perf-stat.ps.dTLB-load-misses
1.412e+10 -10.3% 1.267e+10 perf-stat.ps.dTLB-loads
181859 ± 16% -57.6% 77179 ± 9% perf-stat.ps.dTLB-store-misses
8.227e+09 -10.3% 7.379e+09 perf-stat.ps.dTLB-stores
96313891 -11.0% 85700283 perf-stat.ps.iTLB-load-misses
12236194 +4.0% 12724086 perf-stat.ps.iTLB-loads
4.726e+10 -10.2% 4.245e+10 perf-stat.ps.instructions
16081690 ± 2% +15.0% 18490522 perf-stat.ps.node-load-misses
1571411 ± 2% +10.0% 1728755 ± 2% perf-stat.ps.node-loads
9995103 -11.5% 8842824 perf-stat.ps.node-store-misses
385193 ± 3% -16.0% 323588 ± 7% perf-stat.ps.node-stores
1.445e+13 -10.1% 1.299e+13 perf-stat.total.instructions
1.51 ± 7% -0.2 1.29 ± 7% perf-profile.calltrace.cycles-pp.smpboot_thread_fn.kthread.ret_from_fork
1.53 ± 7% -0.2 1.31 ± 7% perf-profile.calltrace.cycles-pp.ret_from_fork
1.53 ± 7% -0.2 1.31 ± 7% perf-profile.calltrace.cycles-pp.kthread.ret_from_fork
1.48 ± 7% -0.2 1.26 ± 7% perf-profile.calltrace.cycles-pp.rcu_core.__softirqentry_text_start.run_ksoftirqd.smpboot_thread_fn.kthread
1.49 ± 7% -0.2 1.27 ± 7% perf-profile.calltrace.cycles-pp.__softirqentry_text_start.run_ksoftirqd.smpboot_thread_fn.kthread.ret_from_fork
1.50 ± 7% -0.2 1.27 ± 7% perf-profile.calltrace.cycles-pp.run_ksoftirqd.smpboot_thread_fn.kthread.ret_from_fork
1.47 ± 7% -0.2 1.25 ± 7% perf-profile.calltrace.cycles-pp.rcu_do_batch.rcu_core.__softirqentry_text_start.run_ksoftirqd.smpboot_thread_fn
1.41 ± 7% -0.2 1.19 ± 7% perf-profile.calltrace.cycles-pp.kmem_cache_free.rcu_do_batch.rcu_core.__softirqentry_text_start.run_ksoftirqd
1.25 ± 7% -0.2 1.06 ± 7% perf-profile.calltrace.cycles-pp.obj_cgroup_uncharge_pages.kmem_cache_free.rcu_do_batch.rcu_core.__softirqentry_text_start
1.21 ± 7% -0.2 1.03 ± 7% perf-profile.calltrace.cycles-pp.page_counter_uncharge.obj_cgroup_uncharge_pages.kmem_cache_free.rcu_do_batch.rcu_core
0.94 ± 7% -0.1 0.80 ± 7% perf-profile.calltrace.cycles-pp.page_counter_cancel.page_counter_uncharge.obj_cgroup_uncharge_pages.kmem_cache_free.rcu_do_batch
0.62 ± 7% +0.2 0.80 ± 9% perf-profile.calltrace.cycles-pp.tcp_rcv_state_process.tcp_child_process.tcp_v4_rcv.ip_protocol_deliver_rcu.ip_local_deliver_finish
1.51 ± 7% -0.2 1.29 ± 7% perf-profile.children.cycles-pp.smpboot_thread_fn
1.53 ± 7% -0.2 1.31 ± 7% perf-profile.children.cycles-pp.ret_from_fork
1.53 ± 7% -0.2 1.31 ± 7% perf-profile.children.cycles-pp.kthread
1.50 ± 7% -0.2 1.27 ± 7% perf-profile.children.cycles-pp.run_ksoftirqd
1.73 ± 6% -0.2 1.51 ± 5% perf-profile.children.cycles-pp._raw_spin_lock_bh
1.25 ± 5% -0.2 1.07 ± 6% perf-profile.children.cycles-pp.lock_sock_nested
1.03 ± 7% -0.1 0.88 ± 6% perf-profile.children.cycles-pp.native_queued_spin_lock_slowpath
0.83 ± 6% -0.1 0.72 ± 6% perf-profile.children.cycles-pp.sk_clone_lock
0.84 ± 6% -0.1 0.73 ± 6% perf-profile.children.cycles-pp.inet_csk_clone_lock
0.45 ± 8% -0.1 0.34 ± 6% perf-profile.children.cycles-pp.__tcp_get_metrics
0.70 ± 6% -0.1 0.60 ± 6% perf-profile.children.cycles-pp.percpu_counter_add_batch
0.52 ± 8% -0.1 0.42 ± 6% perf-profile.children.cycles-pp.tcp_get_metrics
0.72 ± 5% -0.1 0.62 ± 6% perf-profile.children.cycles-pp.sk_forced_mem_schedule
0.32 ± 7% -0.1 0.24 ± 7% perf-profile.children.cycles-pp.sk_filter_trim_cap
0.49 ± 7% -0.1 0.41 ± 8% perf-profile.children.cycles-pp.tcp_v4_destroy_sock
0.26 ± 7% -0.0 0.22 ± 8% perf-profile.children.cycles-pp.ip_finish_output
0.29 ± 6% -0.0 0.25 ± 9% perf-profile.children.cycles-pp.tcp_write_queue_purge
0.16 ± 10% -0.0 0.12 ± 8% perf-profile.children.cycles-pp.get_obj_cgroup_from_current
0.10 ± 8% -0.0 0.08 ± 6% perf-profile.children.cycles-pp.__destroy_inode
0.10 ± 8% -0.0 0.08 ± 6% perf-profile.children.cycles-pp.destroy_inode
0.10 ± 9% -0.0 0.08 ± 10% perf-profile.children.cycles-pp.sock_put
0.10 ± 10% -0.0 0.07 ± 8% perf-profile.children.cycles-pp.d_instantiate
0.08 ± 11% -0.0 0.06 ± 9% perf-profile.children.cycles-pp.kmem_cache_alloc_trace
0.11 ± 8% +0.0 0.15 ± 6% perf-profile.children.cycles-pp.__inet_lookup_listener
0.08 ± 9% +0.0 0.12 ± 8% perf-profile.children.cycles-pp.inet_lhash2_lookup
0.10 ± 7% +0.0 0.14 ± 7% perf-profile.children.cycles-pp.tcp_ca_openreq_child
0.08 ± 9% +0.0 0.13 ± 9% perf-profile.children.cycles-pp.tcp_newly_delivered
0.08 ± 6% +0.0 0.12 ± 9% perf-profile.children.cycles-pp.tcp_mtup_init
0.09 ± 8% +0.1 0.15 ± 6% perf-profile.children.cycles-pp.tcp_stream_memory_free
0.24 ± 6% +0.1 0.30 ± 8% perf-profile.children.cycles-pp.ip_rcv_core
0.06 ± 9% +0.1 0.12 ± 7% perf-profile.children.cycles-pp.tcp_push
0.11 ± 9% +0.1 0.17 ± 7% perf-profile.children.cycles-pp.tcp_synack_rtt_meas
0.00 ±412% +0.1 0.07 ± 14% perf-profile.children.cycles-pp.tcp_rack_update_reo_wnd
0.20 ± 8% +0.1 0.28 ± 6% perf-profile.children.cycles-pp.tcp_assign_congestion_control
0.34 ± 8% +0.1 0.42 ± 6% perf-profile.children.cycles-pp.tcp_init_metrics
0.14 ± 6% +0.1 0.22 ± 8% perf-profile.children.cycles-pp.tcp_sync_mss
0.33 ± 5% +0.1 0.41 ± 8% perf-profile.children.cycles-pp.inet_csk_route_req
0.31 ± 6% +0.1 0.40 ± 6% perf-profile.children.cycles-pp.inet_csk_route_child_sock
0.13 ± 8% +0.1 0.22 ± 6% perf-profile.children.cycles-pp.skb_entail
0.21 ± 6% +0.1 0.32 ± 7% perf-profile.children.cycles-pp.ip_rcv_finish_core
0.24 ± 5% +0.1 0.35 ± 7% perf-profile.children.cycles-pp.ip_rcv_finish
0.20 ± 7% +0.1 0.32 ± 5% perf-profile.children.cycles-pp.tcp_select_initial_window
0.14 ± 5% +0.1 0.26 ± 8% perf-profile.children.cycles-pp.secure_tcp_ts_off
0.45 ± 6% +0.1 0.58 ± 6% perf-profile.children.cycles-pp.tcp_finish_connect
0.23 ± 5% +0.1 0.35 ± 5% perf-profile.children.cycles-pp.tcp_parse_options
0.17 ± 7% +0.1 0.31 ± 6% perf-profile.children.cycles-pp.tcp_update_pacing_rate
0.20 ± 7% +0.1 0.35 ± 6% perf-profile.children.cycles-pp.tcp_openreq_init_rwin
0.27 ± 9% +0.1 0.42 ± 7% perf-profile.children.cycles-pp.tcp_connect_init
0.45 ± 7% +0.2 0.60 ± 5% perf-profile.children.cycles-pp.tcp_v4_init_sock
0.44 ± 7% +0.2 0.60 ± 6% perf-profile.children.cycles-pp.tcp_init_sock
0.23 ± 7% +0.2 0.39 ± 6% perf-profile.children.cycles-pp.tcp_schedule_loss_probe
0.35 ± 6% +0.2 0.57 ± 7% perf-profile.children.cycles-pp.inet_sk_rebuild_header
0.25 ± 9% +0.2 0.49 ± 7% perf-profile.children.cycles-pp.__tcp_select_window
0.35 ± 6% +0.3 0.61 ± 6% perf-profile.children.cycles-pp.tcp_ack_update_rtt
0.76 ± 5% +0.3 1.04 ± 6% perf-profile.children.cycles-pp.ip_route_output_flow
0.78 ± 6% +0.3 1.08 ± 6% perf-profile.children.cycles-pp.tcp_init_transfer
1.78 ± 6% +0.3 2.11 ± 6% perf-profile.children.cycles-pp.tcp_conn_request
1.07 ± 4% +0.4 1.44 ± 5% perf-profile.children.cycles-pp.ip_route_output_key_hash
1.02 ± 5% +0.4 1.40 ± 5% perf-profile.children.cycles-pp.ip_route_output_key_hash_rcu
2.02 ± 5% +0.5 2.50 ± 6% perf-profile.children.cycles-pp.tcp_ack
1.04 ± 7% +0.6 1.63 ± 7% perf-profile.children.cycles-pp.__sk_dst_check
1.18 ± 7% +0.7 1.86 ± 7% perf-profile.children.cycles-pp.ipv4_dst_check
5.95 ± 5% +0.9 6.87 ± 6% perf-profile.children.cycles-pp.tcp_v4_connect
1.02 ± 7% -0.2 0.87 ± 5% perf-profile.self.cycles-pp.native_queued_spin_lock_slowpath
0.44 ± 8% -0.1 0.34 ± 6% perf-profile.self.cycles-pp.__tcp_get_metrics
0.69 ± 6% -0.1 0.59 ± 6% perf-profile.self.cycles-pp.percpu_counter_add_batch
0.71 ± 5% -0.1 0.61 ± 6% perf-profile.self.cycles-pp.sk_forced_mem_schedule
0.32 ± 6% -0.1 0.26 ± 8% perf-profile.self.cycles-pp.ip_finish_output2
0.35 ± 7% -0.1 0.29 ± 5% perf-profile.self.cycles-pp.tcp_recvmsg_locked
0.15 ± 7% -0.0 0.12 ± 8% perf-profile.self.cycles-pp.exit_to_user_mode_prepare
0.17 ± 6% -0.0 0.14 ± 10% perf-profile.self.cycles-pp.__skb_clone
0.07 ± 5% -0.0 0.04 ± 43% perf-profile.self.cycles-pp.sk_filter_trim_cap
0.09 ± 9% -0.0 0.07 ± 6% perf-profile.self.cycles-pp.dequeue_task_fair
0.08 ± 7% -0.0 0.06 ± 8% perf-profile.self.cycles-pp.release_sock
0.07 ± 10% +0.0 0.09 ± 9% perf-profile.self.cycles-pp.tcp_create_openreq_child
0.11 ± 7% +0.0 0.15 ± 5% perf-profile.self.cycles-pp.tcp_connect
0.08 ± 9% +0.0 0.12 ± 8% perf-profile.self.cycles-pp.inet_lhash2_lookup
0.09 ± 9% +0.0 0.13 ± 6% perf-profile.self.cycles-pp.inet_csk_get_port
0.08 ± 10% +0.0 0.12 ± 8% perf-profile.self.cycles-pp.tcp_init_transfer
0.08 ± 9% +0.0 0.13 ± 8% perf-profile.self.cycles-pp.tcp_newly_delivered
0.07 ± 7% +0.0 0.12 ± 9% perf-profile.self.cycles-pp.tcp_mtup_init
0.35 ± 5% +0.1 0.40 ± 5% perf-profile.self.cycles-pp.__ip_queue_xmit
0.16 ± 7% +0.1 0.22 ± 6% perf-profile.self.cycles-pp.__inet_bind
0.09 ± 8% +0.1 0.15 ± 6% perf-profile.self.cycles-pp.tcp_stream_memory_free
0.24 ± 6% +0.1 0.30 ± 8% perf-profile.self.cycles-pp.ip_rcv_core
0.06 ± 9% +0.1 0.12 ± 6% perf-profile.self.cycles-pp.tcp_push
0.00 +0.1 0.07 ± 11% perf-profile.self.cycles-pp.tcp_rack_update_reo_wnd
0.23 ± 8% +0.1 0.30 ± 6% perf-profile.self.cycles-pp.ip_output
0.20 ± 8% +0.1 0.28 ± 5% perf-profile.self.cycles-pp.tcp_assign_congestion_control
0.10 ± 8% +0.1 0.18 ± 7% perf-profile.self.cycles-pp.tcp_v4_syn_recv_sock
0.09 ± 7% +0.1 0.17 ± 7% perf-profile.self.cycles-pp.tcp_openreq_init_rwin
0.07 ± 10% +0.1 0.16 ± 6% perf-profile.self.cycles-pp.tcp_v4_send_synack
0.13 ± 7% +0.1 0.22 ± 7% perf-profile.self.cycles-pp.tcp_sync_mss
0.12 ± 8% +0.1 0.20 ± 7% perf-profile.self.cycles-pp.skb_entail
0.18 ± 8% +0.1 0.27 ± 6% perf-profile.self.cycles-pp.ip_protocol_deliver_rcu
0.21 ± 5% +0.1 0.31 ± 6% perf-profile.self.cycles-pp.ip_rcv_finish_core
0.15 ± 9% +0.1 0.26 ± 6% perf-profile.self.cycles-pp.tcp_update_metrics
0.20 ± 8% +0.1 0.31 ± 5% perf-profile.self.cycles-pp.tcp_select_initial_window
0.12 ± 9% +0.1 0.25 ± 8% perf-profile.self.cycles-pp.tcp_connect_init
0.11 ± 8% +0.1 0.24 ± 8% perf-profile.self.cycles-pp.secure_tcp_ts_off
0.22 ± 5% +0.1 0.35 ± 5% perf-profile.self.cycles-pp.tcp_parse_options
0.13 ± 12% +0.1 0.27 ± 7% perf-profile.self.cycles-pp.tcp_init_metrics
0.17 ± 7% +0.1 0.30 ± 7% perf-profile.self.cycles-pp.tcp_update_pacing_rate
0.17 ± 10% +0.2 0.32 ± 6% perf-profile.self.cycles-pp.tcp_init_sock
0.18 ± 8% +0.2 0.35 ± 6% perf-profile.self.cycles-pp.tcp_schedule_loss_probe
0.42 ± 8% +0.2 0.62 ± 7% perf-profile.self.cycles-pp.tcp_write_xmit
0.25 ± 8% +0.2 0.48 ± 7% perf-profile.self.cycles-pp.__tcp_select_window
0.28 ± 8% +0.3 0.56 ± 5% perf-profile.self.cycles-pp.tcp_ack_update_rtt
0.71 ± 5% +0.4 1.09 ± 6% perf-profile.self.cycles-pp.ip_route_output_key_hash_rcu
1.17 ± 7% +0.7 1.84 ± 7% perf-profile.self.cycles-pp.ipv4_dst_check
netperf.Throughput_tps
22500 +-------------------------------------------------------------------+
| ...+...... ...+......+.....+.....|
22000 |.....+.. +.....+.....+.....+.....+.. |
| |
| |
21500 |-+ |
| |
21000 |-+ |
| |
20500 |-+ |
| |
| |
20000 |-+ |
| O O O O O |
19500 +-------------------------------------------------------------------+
netperf.Throughput_total_tps
360000 +------------------------------------------------------------------+
355000 |-+ ...+..... ...+..... ...+.. +.....|
|.....+.. +.....+.....+... +.. |
350000 |-+ |
345000 |-+ |
| |
340000 |-+ |
335000 |-+ |
330000 |-+ |
| |
325000 |-+ |
320000 |-+ |
| |
315000 |-+ O O O O O O O O O O |
310000 +------------------------------------------------------------------+
netperf.workload
1.08e+08 +----------------------------------------------------------------+
| ...+.....+..... ..+..... ...+.. +.....|
1.06e+08 |.....+.. +.....+.. +.. |
1.04e+08 |-+ |
| |
1.02e+08 |-+ |
| |
1e+08 |-+ |
| |
9.8e+07 |-+ |
9.6e+07 |-+ |
| |
9.4e+07 |-+ O O O O O O O O O O |
| |
9.2e+07 +----------------------------------------------------------------+
netperf.time.voluntary_context_switches
2.1e+08 +----------------------------------------------------------------+
|.....+.....+.....+.....+.....+....+..... ...+.. +.....|
2.05e+08 |-+ +.. |
| |
| |
2e+08 |-+ |
| |
1.95e+08 |-+ |
| |
1.9e+08 |-+ |
| |
| |
1.85e+08 |-+ O O O O O O O |
| O O O |
1.8e+08 +----------------------------------------------------------------+
0.006 +------------------------------------------------------------------+
| |
| |
0.0058 |-+ |
| |
| |
0.0056 |-+ |
| |
0.0054 |-+ |
| |
| |
0.0052 |-+ |
| |
| |
0.005 +------------------------------------------------------------------+
3.25e+06 +----------------------------------------------------------------+
|..... ...+.... ...+....+.....+.....+..... ...+.....|
3.2e+06 |-+ +.. . ...+.. +.. |
| +.. |
3.15e+06 |-+ |
3.1e+06 |-+ |
| |
3.05e+06 |-+ |
| |
3e+06 |-+ |
2.95e+06 |-+ |
| |
2.9e+06 |-+ O O O O O O O O O |
| O |
2.85e+06 +----------------------------------------------------------------+
[*] bisect-good sample
[O] bisect-bad sample
***************************************************************************************************
lkp-icl-2sp1: 96 threads 2 sockets Ice Lake with 256G memory
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.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
6 months
[objtool,x86] 134ab5bd18: leaking-addresses.proc..retpoline_sites.
by kernel test robot
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 134ab5bd1883312d7a4b3033b05c6b5a1bb8889b ("objtool,x86: Replace alternatives with .retpoline_sites")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: leaking-addresses
version: leaking-addresses-x86_64-4f19048-1_20211101
with following parameters:
ucode: 0x28
on test machine: 8 threads 1 sockets Intel(R) Core(TM) i7-4770 CPU @ 3.40GHz with 16G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
2021-11-02 15:19:52 ./leaking_addresses.pl --output-raw result/scan.out
2021-11-02 15:20:10 ./leaking_addresses.pl --input-raw result/scan.out --squash-by-filename
Total number of results from scan (incl dmesg): 156272
dmesg output:
[ 1.890044] mapped IOAPIC to ffffffffff5fb000 (fec00000)
Results squashed by filename (excl dmesg). Displaying [<number of results> <filename>], <example result>
[9 .data.once] 0xffffffffc026e638
[34 .rodata] 0xffffffffc006d2c0
[20 __jump_table] 0xffffffffc006e000
[15 __dyndbg] 0xffffffffc006f0c8
[33 .rodata.str1.8] 0xffffffffc006d180
[6 .static_call.text] 0xffffffffc00dfb44
[19 __ksymtab] 0xffffffffc043a054
[34 .data] 0xffffffffc006f000
[13 .parainstructions] 0xffffffffc0462dd8
[10 __ex_table] 0xffffffffc0075140
[29 .text.unlikely] 0xffffffffc006cc5c
[43 modules] btrfs 1716224 1 - Live 0xffffffffc0572000
[1 .rodata.cst16.mask2] 0xffffffffc0060100
[24 __ksymtab_strings] 0xffffffffc043a060
[1 .rodata.cst32.byteshift_table] 0xffffffffc0060120
[1 .rodata.cst16.mask1] 0xffffffffc00600f0
[43 .orc_unwind] 0xffffffffc006d3a0
[6 __tracepoints_ptrs] 0xffffffffc00e91b4
[1 _error_injection_whitelist] 0xffffffffc06dbb40
[18 .altinstructions] 0xffffffffc0462df4
[149 printk_formats] 0xffffffff8253db85 : "CPU_ON"
[345 blacklist] 0xffffffff81e00880-0xffffffff81e008a0 asm_exc_overflow
[1 wchan] 0xffffc9000002fe48/sys/kernel/debug/kprobes/blacklist: 0xffffffff81e00860-0xffffffff81e00880 asm_exc_divide_error
[31 .retpoline_sites] 0xffffffffc043a1df
[42 __mcount_loc] 0xffffffffc006d054
[23 .smp_locks] 0xffffffffc006d2b4
[7 .static_call_sites] 0xffffffffc06d8208
[43 .note.Linux] 0xffffffffc006d024
[6 .ref.data] 0xffffffffc00edac0
[17 __param] 0xffffffffc006d378
[43 .gnu.linkonce.this_module] 0xffffffffc006f140
[4 .altinstr_aux] 0xffffffffc04d5c37
[2 .noinstr.text] 0xffffffffc04d5d00
[43 .symtab] 0xffffffffc0086000
[43 .text] 0xffffffffc006c000
[6 __bpf_raw_tp_map] 0xffffffffc00eda40
[1 ___srcu_struct_ptrs] 0xffffffffc0400ca8
[29 .exit.text] 0xffffffffc006cd1d
[2 _ftrace_eval_map] 0xffffffffc06d60e8
[18 .altinstr_replacement] 0xffffffffc0461cb7
[6 .fixup] 0xffffffffc0097396
[32 .init.text] 0xffffffffc0084000
[8 .init.rodata] 0xffffffffc0085000
[6 __tracepoints_strings] 0xffffffffc00e91c0
[43 .orc_unwind_ip] 0xffffffffc006d616
[43 .strtab] 0xffffffffc0086ba0
[5 .init.data] 0xffffffffc0236000
[12 __ksymtab_gpl] 0xffffffffc0462054
[1 .data..cacheline_aligned] 0xffffffffc0a64a40
[2 .rodata.cst16.bswap_mask] 0xffffffffc0226090
[43 .note.gnu.build-id] 0xffffffffc006d000
[6 _ftrace_events] 0xffffffffc00edaa0
[10 .data..read_mostly] 0xffffffffc006f100
[6 __tracepoints] 0xffffffffc00edbe0
[154748 kallsyms] ffffffff81000000 T startup_64
[28 .bss] 0xffffffffc006f4c0
[22 __bug_table] 0xffffffffc033e070
[35 .rodata.str1.1] 0xffffffffc006d0ac
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
6 months, 1 week
[nvmet] 2953b30b1d: blktests.nvme/002.fail
by kernel test robot
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 2953b30b1d9feb1bc555682e64e6479d197b9231 ("nvmet: register discovery subsystem as 'current'")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: blktests
version: blktests-x86_64-3be7849-1_20211102
with following parameters:
disk: 1SSD
test: nvme-group-01
ucode: 0x11
on test machine: 288 threads 2 sockets Intel(R) Xeon Phi(TM) CPU 7295 @ 1.50GHz with 80G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
2021-11-11 10:12:34 sed "s:^:nvme/:" /lkp/benchmarks/blktests/tests/nvme-group-01
2021-11-11 10:12:34 ./check -o /mnt/nvme-group-01 nvme/002 nvme/003
nvme/002 (create many subsystems and test discovery)
nvme/002 (create many subsystems and test discovery) [failed]
runtime ... 66.722s
--- tests/nvme/002.out 2021-11-02 07:05:50.000000000 +0000
+++ /mnt/nvme-group-01/nodev/nvme/002.out.bad 2021-11-11 10:13:41.210659687 +0000
@@ -1,3003 +1,3006 @@
Running nvme/002
-Discovery Log Number of Records 1000, Generation counter X
+Discovery Log Number of Records 1001, Generation counter X
=====Discovery Log Entry 0======
trtype: loop
-subnqn: blktests-subsystem-0
+subnqn: nqn.2014-08.org.nvmexpress.discovery
...
(Run 'diff -u tests/nvme/002.out /mnt/nvme-group-01/nodev/nvme/002.out.bad' to see the entire diff)
nvme/003 (test if we're sending keep-alives to a discovery controller)
nvme/003 (test if we're sending keep-alives to a discovery controller) [passed]
runtime ... 10.551s
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
6 months, 1 week
[powercap/drivers/dtpm] 7a89d7eacf: WARNING:at_kernel/cpu.c:#_cpu_down
by kernel test robot
Greeting,
FYI, we noticed the following commit (built with clang-14):
commit: 7a89d7eacf8e84f2afb94db5ae9d9f9faa93f01c ("powercap/drivers/dtpm: Simplify the dtpm table")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------------------------------------------+------------+------------+
| | 4570ddda43 | 7a89d7eacf |
+--------------------------------------------------------------------------+------------+------------+
| WARNING:at_kernel/cpu.c:#_cpu_down | 0 | 15 |
| EIP:_cpu_down | 0 | 15 |
+--------------------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
[ 79.790957][ T1] WARNING: CPU: 1 PID: 1 at kernel/cpu.c:1106 _cpu_down (kernel/cpu.c:1105 kernel/cpu.c:1157)
[ 79.791765][ T1] Modules linked in:
[ 79.792145][ T1] CPU: 1 PID: 1 Comm: swapper/0 Tainted: G W 5.15.0-rc1-00002-g7a89d7eacf8e #1
[ 79.793167][ T1] EIP: _cpu_down (kernel/cpu.c:1105 kernel/cpu.c:1157)
[ 79.793621][ T1] Code: 2d 24 fa fe 45 f0 31 db 45 f0 31 db c3 b8 10 8e c3 b8 10 8e 31 c9 6a 00 31 c9 6a 00 ff 83 c4 04 ff 83 c4 04 74 02 0f 0b 74 02 <0f> 0b 86 89 da 31 86 89 da 31 75 29 0e ff 75 29 0e ff 06 3b 45 e4
All code
========
0: 2d 24 fa fe 45 sub $0x45fefa24,%eax
5: f0 31 db lock xor %ebx,%ebx
8: 45 rex.RB
9: f0 31 db lock xor %ebx,%ebx
c: c3 retq
d: b8 10 8e c3 b8 mov $0xb8c38e10,%eax
12: 10 8e 31 c9 6a 00 adc %cl,0x6ac931(%rsi)
18: 31 c9 xor %ecx,%ecx
1a: 6a 00 pushq $0x0
1c: ff 83 c4 04 ff 83 incl -0x7c00fb3c(%rbx)
22: c4 (bad)
23: 04 74 add $0x74,%al
25: 02 0f add (%rdi),%cl
27:* 0b 74 02 0f or 0xf(%rdx,%rax,1),%esi <-- trapping instruction
2b: 0b 86 89 da 31 86 or -0x79ce2577(%rsi),%eax
31: 89 da mov %ebx,%edx
33: 31 75 29 xor %esi,0x29(%rbp)
36: 0e (bad)
37: ff 75 29 pushq 0x29(%rbp)
3a: 0e (bad)
3b: ff 06 incl (%rsi)
3d: 3b 45 e4 cmp -0x1c(%rbp),%eax
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 86 89 da 31 86 89 xchg %cl,-0x7679ce26(%rcx)
8: da 31 fidivl (%rcx)
a: 75 29 jne 0x35
c: 0e (bad)
d: ff 75 29 pushq 0x29(%rbp)
10: 0e (bad)
11: ff 06 incl (%rsi)
13: 3b 45 e4 cmp -0x1c(%rbp),%eax
[ 79.795648][ T1] EAX: 00000001 EBX: 00000001 ECX: 00000000 EDX: ffffffff
[ 79.796398][ T1] ESI: f44af954 EDI: 00000000 EBP: 812f9d78 ESP: 812f9d50
[ 79.797136][ T1] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010282
[ 79.797895][ T1] CR0: 80050033 CR2: 77f07104 CR3: 06ee0000 CR4: 00040690
[ 79.798594][ T1] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 79.799314][ T1] DR6: fffe0ff0 DR7: 00000400
[ 79.799769][ T1] Call Trace:
[ 79.800119][ T1] cpu_down_maps_locked (kernel/cpu.c:1184)
[ 79.800637][ T1] cpu_down (kernel/cpu.c:1191)
[ 79.801064][ T1] cpu_device_down (kernel/cpu.c:1208)
[ 79.801513][ T1] cpu_subsys_offline (drivers/base/cpu.c:72)
[ 79.801997][ T1] device_offline (drivers/base/core.c:3842)
[ 79.802486][ T1] remove_cpu (kernel/cpu.c:1216)
[ 79.802898][ T1] _debug_hotplug_cpu (arch/x86/kernel/topology.c:72)
[ 79.803364][ T1] debug_hotplug_cpu (arch/x86/kernel/topology.c:93)
[ 79.803842][ T1] do_one_initcall (init/main.c:?)
[ 79.804353][ T1] ? early_platform_quirks (arch/x86/kernel/topology.c:91)
[ 79.804909][ T1] do_initcall_level (init/main.c:1375)
[ 79.805416][ T1] do_initcalls (init/main.c:1389)
[ 79.805935][ T1] do_basic_setup (init/main.c:1412)
[ 79.806401][ T1] kernel_init_freeable (init/main.c:1616)
[ 79.806927][ T1] ? kernel_init (init/main.c:1507)
[ 79.807388][ T1] ? rest_init (init/main.c:1497)
[ 79.807857][ T1] kernel_init (init/main.c:1507)
[ 79.808309][ T1] ret_from_fork (??:?)
[ 79.808778][ T1] irq event stamp: 7852087
[ 79.809290][ T1] hardirqs last enabled at (7852097): __up_console_sem (arch/x86/include/asm/irqflags.h:22 arch/x86/include/asm/irqflags.h:70 arch/x86/include/asm/irqflags.h:132 kernel/printk/printk.c:255)
[ 79.810211][ T1] hardirqs last disabled at (7852104): __up_console_sem (kernel/printk/printk.c:253)
[ 79.811121][ T1] softirqs last enabled at (7828330): __do_softirq (arch/x86/include/asm/preempt.h:27 kernel/softirq.c:402 kernel/softirq.c:587)
[ 79.811974][ T1] softirqs last disabled at (7828325): do_softirq_own_stack (arch/x86/kernel/irq_32.c:60 arch/x86/kernel/irq_32.c:149)
[ 79.813005][ T1] ---[ end trace 468a5b8e1524c1ed ]---
[ 79.813602][ T1] ------------[ cut here ]------------
[ 79.814173][ T1] DEAD callback error for CPU0
To reproduce:
# build kernel
cd linux
cp config-5.15.0-rc1-00002-g7a89d7eacf8e .config
make HOSTCC=clang-14 CC=clang-14 ARCH=i386 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
6 months, 1 week
[af_unix] 95e381b609: WARNING:possible_recursive_locking_detected
by kernel test robot
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 95e381b6095d0808a64ecbe36515cca2ea2df477 ("[PATCH net-next 12/13] af_unix: Replace the big lock with small locks.")
url: https://github.com/0day-ci/linux/commits/Kuniyuki-Iwashima/af_unix-Replac...
base: https://git.kernel.org/cgit/linux/kernel/git/davem/net-next.git 84882cf72cd774cf16fd338bdbf00f69ac9f9194
patch link: https://lore.kernel.org/netdev/20211106091712.15206-13-kuniyu@amazon.co.jp
in testcase: kernel-selftests
version: kernel-selftests-x86_64-c8c9111a-1_20210929
with following parameters:
group: x86
ucode: 0xde
test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel.
test-url: https://www.kernel.org/doc/Documentation/kselftest.txt
on test machine: 4 threads 1 sockets Intel(R) Core(TM) i7-7567U CPU @ 3.50GHz with 32G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+---------------------------------------------+------------+------------+
| | 5c1456529e | 95e381b609 |
+---------------------------------------------+------------+------------+
| boot_successes | 4 | 0 |
| boot_failures | 0 | 4 |
| WARNING:possible_recursive_locking_detected | 0 | 4 |
+---------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
kern :warn : [ 39.215794] WARNING: possible recursive locking detected
kern :warn : [ 39.216286] 5.15.0-rc7-02477-g95e381b6095d #1 Not tainted
kern :warn : [ 39.216816] --------------------------------------------
kern :warn : [ 39.217306] systemd/1 is trying to acquire lock:
kern :warn : [ 39.217783] ffffffff87c53fb8 (&unix_table_locks[i]){+.+.}-{2:2}, at: unix_bind (net/unix/af_unix.c:1176 net/unix/af_unix.c:1253)
kern :warn : [ 39.218514]
but task is already holding lock:
kern :warn : [ 39.219142] ffffffff87c4de38 (&unix_table_locks[i]){+.+.}-{2:2}, at: unix_table_double_lock (net/unix/af_unix.c:170)
kern :warn : [ 39.219969]
other info that might help us debug this:
kern :warn : [ 39.220611] Possible unsafe locking scenario:
kern :warn : [ 39.221209] CPU0
kern :warn : [ 39.221499] ----
kern :warn : [ 39.221789] lock(&unix_table_locks[i]);
kern :warn : [ 39.222191] lock(&unix_table_locks[i]);
kern :warn : [ 39.222592]
*** DEADLOCK ***
kern :warn : [ 39.223256] May be due to missing lock nesting notation
kern :warn : [ 39.223919] 4 locks held by systemd/1:
kern :warn : [ 39.224301] #0: ffff8888765ca448 (sb_writers#6){.+.+}-{0:0}, at: filename_create (fs/namei.c:3656)
kern :warn : [ 39.225037] #1: ffff888100275280 (&type->i_mutex_dir_key#4/1){+.+.}-{3:3}, at: filename_create (fs/namei.c:3657)
kern :warn : [ 39.225863] #2: ffff888874f82e18 (&u->bindlock){+.+.}-{3:3}, at: unix_bind (net/unix/af_unix.c:1168 net/unix/af_unix.c:1253)
kern :warn : [ 39.226571] #3: ffffffff87c4de38 (&unix_table_locks[i]){+.+.}-{2:2}, at: unix_table_double_lock (net/unix/af_unix.c:170)
kern :warn : [ 39.227394]
stack backtrace:
kern :warn : [ 39.227885] CPU: 2 PID: 1 Comm: systemd Not tainted 5.15.0-rc7-02477-g95e381b6095d #1
kern :warn : [ 39.228571] Hardware name: Intel Corporation NUC7i7BNH/NUC7i7BNB, BIOS BNKBL357.86A.0067.2018.0814.1500 08/14/2018
kern :warn : [ 39.229434] Call Trace:
kern :warn : [ 39.229727] dump_stack_lvl (lib/dump_stack.c:107)
kern :warn : [ 39.230107] __lock_acquire.cold (kernel/locking/lockdep.c:2944 kernel/locking/lockdep.c:2987 kernel/locking/lockdep.c:3776 kernel/locking/lockdep.c:5015)
kern :warn : [ 39.230530] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4873)
kern :warn : [ 39.231012] ? lock_is_held_type (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5669)
kern :warn : [ 39.231426] ? lockdep_hardirqs_on_prepare (kernel/locking/lockdep.c:4873)
kern :warn : [ 39.231907] ? lock_is_held_type (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5669)
kern :warn : [ 39.232321] ? rcu_read_lock_sched_held (include/linux/lockdep.h:283 kernel/rcu/update.c:125)
kern :warn : [ 39.232779] lock_acquire (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5627 kernel/locking/lockdep.c:5590)
kern :warn : [ 39.233155] ? unix_bind (net/unix/af_unix.c:1176 net/unix/af_unix.c:1253)
kern :warn : [ 39.233533] ? rcu_read_unlock (include/linux/rcupdate.h:716 (discriminator 5))
kern :warn : [ 39.233932] ? do_raw_spin_lock (arch/x86/include/asm/atomic.h:202 include/linux/atomic/atomic-instrumented.h:513 include/asm-generic/qspinlock.h:82 kernel/locking/spinlock_debug.c:115)
kern :warn : [ 39.234346] ? rwlock_bug+0xc0/0xc0
kern :warn : [ 39.234757] _raw_spin_lock (include/linux/spinlock_api_smp.h:143 kernel/locking/spinlock.c:154)
kern :warn : [ 39.235135] ? unix_bind (net/unix/af_unix.c:1176 net/unix/af_unix.c:1253)
kern :warn : [ 39.235513] unix_bind (net/unix/af_unix.c:1176 net/unix/af_unix.c:1253)
kern :warn : [ 39.235880] ? unix_socketpair (net/unix/af_unix.c:1239)
kern :warn : [ 39.236289] ? _copy_from_user (arch/x86/include/asm/uaccess_64.h:46 arch/x86/include/asm/uaccess_64.h:52 lib/usercopy.c:16)
kern :warn : [ 39.236694] __sys_bind (net/socket.c:1693)
kern :warn : [ 39.237061] ? __ia32_sys_socketpair (net/socket.c:1680)
kern :warn : [ 39.237504] ? lock_is_held_type (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5669)
kern :warn : [ 39.237919] ? lock_is_held_type (kernel/locking/lockdep.c:438 kernel/locking/lockdep.c:5669)
kern :warn : [ 39.238332] ? syscall_enter_from_user_mode (kernel/entry/common.c:107)
kern :warn : [ 39.241493] ? rcu_read_lock_sched_held (include/linux/lockdep.h:283 kernel/rcu/update.c:125)
kern :warn : [ 39.241951] ? rcu_read_lock_bh_held (kernel/rcu/update.c:120)
kern :warn : [ 39.242382] ? do_syscall_64 (arch/x86/entry/common.c:87)
kern :warn : [ 39.242768] __x64_sys_bind (net/socket.c:1702)
kern :warn : [ 39.243145] ? syscall_enter_from_user_mode (arch/x86/include/asm/irqflags.h:45 arch/x86/include/asm/irqflags.h:80 kernel/entry/common.c:107)
kern :warn : [ 39.243620] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
kern :warn : [ 39.243994] ? do_syscall_64 (arch/x86/entry/common.c:87)
kern :warn : [ 39.244378] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4344)
kern :warn : [ 39.244803] ? do_syscall_64 (arch/x86/entry/common.c:87)
kern :warn : [ 39.245188] ? do_syscall_64 (arch/x86/entry/common.c:87)
kern :warn : [ 39.245571] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4344)
kern :warn : [ 39.245997] ? do_syscall_64 (arch/x86/entry/common.c:87)
kern :warn : [ 39.246380] ? asm_sysvec_apic_timer_interrupt (arch/x86/include/asm/idtentry.h:638)
kern :warn : [ 39.246873] ? asm_sysvec_apic_timer_interrupt (arch/x86/include/asm/idtentry.h:638)
kern :warn : [ 39.247359] ? lockdep_hardirqs_on (kernel/locking/lockdep.c:4344)
kern :warn : [ 39.247786] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113)
kern :warn : [ 39.248260] RIP: 0033:0x7f84b7e22497
kern :warn : [ 39.248632] Code: ff ff ff ff c3 48 8b 15 f7 09 0c 00 f7 d8 64 89 02 b8 ff ff ff ff eb ba 66 2e 0f 1f 84 00 00 00 00 00 90 b8 31 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d c9 09 0c 00 f7 d8 64 89 01 48
All code
========
0: ff (bad)
1: ff (bad)
2: ff (bad)
3: ff c3 inc %ebx
5: 48 8b 15 f7 09 0c 00 mov 0xc09f7(%rip),%rdx # 0xc0a03
c: f7 d8 neg %eax
e: 64 89 02 mov %eax,%fs:(%rdx)
11: b8 ff ff ff ff mov $0xffffffff,%eax
16: eb ba jmp 0xffffffffffffffd2
18: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
1f: 00 00 00
22: 90 nop
23: b8 31 00 00 00 mov $0x31,%eax
28: 0f 05 syscall
2a:* 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax <-- trapping instruction
30: 73 01 jae 0x33
32: c3 retq
33: 48 8b 0d c9 09 0c 00 mov 0xc09c9(%rip),%rcx # 0xc0a03
3a: f7 d8 neg %eax
3c: 64 89 01 mov %eax,%fs:(%rcx)
3f: 48 rex.W
Code starting with the faulting instruction
===========================================
0: 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax
6: 73 01 jae 0x9
8: c3 retq
9: 48 8b 0d c9 09 0c 00 mov 0xc09c9(%rip),%rcx # 0xc09d9
10: f7 d8 neg %eax
12: 64 89 01 mov %eax,%fs:(%rcx)
15: 48 rex.W
kern :warn : [ 39.250101] RSP: 002b:00007ffd7751fa58 EFLAGS: 00000246 ORIG_RAX: 0000000000000031
kern :warn : [ 39.250770] RAX: ffffffffffffffda RBX: 0000559d4fc70bb0 RCX: 00007f84b7e22497
kern :warn : [ 39.251406] RDX: 0000000000000016 RSI: 00007ffd7751fa70 RDI: 000000000000000f
kern :warn : [ 39.252042] RBP: 00007ffd7751fa70 R08: 000000000000000c R09: 0000559d4fcd6670
kern :warn : [ 39.252679] R10: 00007ffd7751fa24 R11: 0000000000000246 R12: 000000000000000f
kern :warn : [ 39.253314] R13: 0000000000000016 R14: 00007ffd7751fb50 R15: 00007ffd7751fb48
kern :notice: [ 39.425532] random: systemd-random-: uninitialized urandom read (512 bytes read)
kern :info : [ 39.905355] intel_pmc_core INT33A1:00: initialized
kern :debug : [ 40.139879] IOAPIC[2]: Set IRTE entry (P:1 FPD:0 Dst_Mode:1 Redir_hint:1 Trig_Mode:0 Dlvry_Mode:0 Avail:0 Vector:EF Dest:00000001 SID:F0F8 SQ:0 SVT:1)
kern :debug : [ 40.141118] IOAPIC[0]: Preconfigured routing entry (2-18 -> IRQ 18 Level:1 ActiveLow:1)
kern :info : [ 40.186707] mei_me 0000:00:16.0: enabling device (0004 -> 0006)
kern :debug : [ 40.196333] libata version 3.00 loaded.
kern :notice: [ 40.361505] random: dbus-daemon: uninitialized urandom read (12 bytes read)
kern :notice: [ 40.365282] random: dbus-daemon: uninitialized urandom read (12 bytes read)
kern :info : [ 40.969470] microcode: updated to revision 0xde, date = 2020-05-27
kern :warn : [ 40.970115] x86/CPU: CPU features have changed after loading microcode, but might not take effect.
kern :warn : [ 40.971061] x86/CPU: Please consider either early loading through initrd/built-in or a potential BIOS update.
kern :info : [ 40.971992] microcode: Reload completed, microcode revision: 0xde
kern :info : [ 41.013694] i801_smbus 0000:00:1f.4: SPD Write Disable is set
kern :info : [ 41.014375] i801_smbus 0000:00:1f.4: SMBus using PCI interrupt
kern :info : [ 41.015800] IPMI message handler: version 39.2
kern :info : [ 41.022407] iTCO_wdt iTCO_wdt: Found a Intel PCH TCO device (Version=4, TCOBASE=0x0400)
kern :info : [ 41.023587] ipmi device interface
kern :info : [ 41.033277] iTCO_wdt iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
kern :notice: [ 41.048766] random: ln: uninitialized urandom read (6 bytes read)
kern :debug : [ 41.068893] ahci 0000:00:17.0: version 3.0
kern :info : [ 41.115078] ipmi_si: IPMI System Interface driver
kern :warn : [ 41.117158] ipmi_si: Unable to find any System Interface(s)
kern :info : [ 41.117819] ahci 0000:00:17.0: AHCI 0001.0301 32 slots 2 ports 6 Gbps 0x5 impl SATA mode
kern :info : [ 41.118556] ahci 0000:00:17.0: flags: 64bit ncq pm led clo only pio slum part deso sadm sds apst
kern :notice: [ 41.138009] random: ln: uninitialized urandom read (6 bytes read)
kern :info : [ 41.170985] RAPL PMU: API unit is 2^-32 Joules, 5 fixed counters, 655360 ms ovfl timer
kern :info : [ 41.171706] RAPL PMU: hw unit of domain pp0-core 2^-14 Joules
kern :info : [ 41.172240] RAPL PMU: hw unit of domain package 2^-14 Joules
kern :info : [ 41.172781] RAPL PMU: hw unit of domain dram 2^-14 Joules
kern :info : [ 41.173296] RAPL PMU: hw unit of domain pp1-gpu 2^-14 Joules
kern :info : [ 41.174495] RAPL PMU: hw unit of domain psys 2^-14 Joules
kern :info : [ 41.220484] scsi host0: ahci
kern :info : [ 41.235600] i2c i2c-0: 2/2 memory slots populated (from DMI)
kern :info : [ 41.236463] scsi host1: ahci
kern :info : [ 41.243332] i2c i2c-0: Successfully instantiated SPD at 0x50
kern :info : [ 41.251989] scsi host2: ahci
kern :info : [ 41.254369] ata1: SATA max UDMA/133 abar m2048@0xdc24b000 port 0xdc24b100 irq 129
kern :info : [ 41.255076] ata2: DUMMY
kern :info : [ 41.255403] ata3: SATA max UDMA/133 abar m2048@0xdc24b000 port 0xdc24b200 irq 129
kern :info : [ 41.428685] i915 0000:00:02.0: [drm] Found 64MB of eDRAM
kern :info : [ 41.429635] i915 0000:00:02.0: vgaarb: deactivate vga console
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
6 months, 1 week
[rtc] 1d1bb12a8b: WARNING:at_kernel/time/clocksource-wdtest.c:#wdtest_func
by kernel test robot
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 1d1bb12a8b1805ddeef9793ebeb920179fb0fa38 ("rtc: Improve performance of rtc_time64_to_tm(). Add tests.")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: boot
on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+----------------------------------------------------------------------+------------+------------+
| | fffd603ae9 | 1d1bb12a8b |
+----------------------------------------------------------------------+------------+------------+
| WARNING:at_kernel/time/clocksource-wdtest.c:#wdtest_func | 0 | 76 |
| EIP:wdtest_func | 0 | 76 |
+----------------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
[ 287.616398][ T134] WARNING: CPU: 0 PID: 134 at kernel/time/clocksource-wdtest.c:154 wdtest_func (kernel/time/clocksource-wdtest.c:154 (discriminator 1))
[ 287.617518][ T134] Modules linked in:
[ 287.617903][ T134] CPU: 0 PID: 134 Comm: wdtest Not tainted 5.14.0-rc1-g1d1bb12a8b18 #1 80e6223961f27d88bdaabe41fd9095aa927907a3
[ 287.619086][ T134] EIP: wdtest_func (kernel/time/clocksource-wdtest.c:154 (discriminator 1))
[ 287.619583][ T134] Code: 6d b0 9c 00 a1 a4 68 0d 43 83 c4 10 85 c0 74 02 0f 0b a1 24 72 79 42 39 1d 50 5f 79 42 0f 93 c1 83 e0 40 0f 94 c2 38 d1 74 02 <0f> 0b 85 c0 74 32 b8 e0 71 79 42 e8 f5 a4 ff ff b8 0a 00 00 00 c7
All code
========
0: 6d insl (%dx),%es:(%rdi)
1: b0 9c mov $0x9c,%al
3: 00 a1 a4 68 0d 43 add %ah,0x430d68a4(%rcx)
9: 83 c4 10 add $0x10,%esp
c: 85 c0 test %eax,%eax
e: 74 02 je 0x12
10: 0f 0b ud2
12: a1 24 72 79 42 39 1d movabs 0x5f501d3942797224,%eax
19: 50 5f
1b: 79 42 jns 0x5f
1d: 0f 93 c1 setae %cl
20: 83 e0 40 and $0x40,%eax
23: 0f 94 c2 sete %dl
26: 38 d1 cmp %dl,%cl
28: 74 02 je 0x2c
2a:* 0f 0b ud2 <-- trapping instruction
2c: 85 c0 test %eax,%eax
2e: 74 32 je 0x62
30: b8 e0 71 79 42 mov $0x427971e0,%eax
35: e8 f5 a4 ff ff callq 0xffffffffffffa52f
3a: b8 0a 00 00 00 mov $0xa,%eax
3f: c7 .byte 0xc7
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 85 c0 test %eax,%eax
4: 74 32 je 0x38
6: b8 e0 71 79 42 mov $0x427971e0,%eax
b: e8 f5 a4 ff ff callq 0xffffffffffffa505
10: b8 0a 00 00 00 mov $0xa,%eax
15: c7 .byte 0xc7
[ 287.621537][ T134] EAX: 00000040 EBX: 00000002 ECX: c70df901 EDX: 00000000
[ 287.622223][ T134] ESI: 000001df EDI: 43650000 EBP: 43653f80 ESP: 43653f78
[ 287.622927][ T134] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010202
[ 287.623659][ T134] CR0: 80050033 CR2: 3f849fb0 CR3: 7f87c000 CR4: 00040690
[ 287.624356][ T134] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 287.625027][ T134] DR6: fffe0ff0 DR7: 00000400
[ 287.625477][ T134] Call Trace:
[ 287.625794][ T134] ? kthread (kernel/kthread.c:321)
[ 287.626275][ T134] ? wdtest_ktime_read (kernel/time/clocksource-wdtest.c:106)
[ 287.626769][ T134] ? set_kthread_struct (kernel/kthread.c:272)
[ 287.627281][ T134] ? ret_from_fork (arch/x86/entry/entry_32.S:775)
[ 287.627786][ T134] irq event stamp: 277
[ 287.628202][ T134] hardirqs last enabled at (285): console_unlock (arch/x86/include/asm/irqflags.h:29 (discriminator 3) arch/x86/include/asm/irqflags.h:70 (discriminator 3) arch/x86/include/asm/irqflags.h:132 (discriminator 3) kernel/printk/printk.c:2668 (discriminator 3))
[ 287.629062][ T134] hardirqs last disabled at (292): console_unlock (kernel/printk/printk.c:2589 (discriminator 1))
[ 287.629829][ T134] softirqs last enabled at (0): copy_process (kernel/fork.c:2006)
[ 287.630700][ T134] softirqs last disabled at (0): 0x0
[ 287.631371][ T134] ---[ end trace 6106d07b95b92b97 ]---
[ 287.741573][ T134] clocksource: wdtest-ktime: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[ 287.742824][ T134] clocksource_wdtest: --- Watchdog with 3x error injection, 3 retries, expect message.
[ 288.252664][ C0] clocksource: timekeeping watchdog on CPU0: kvm-clock retried 3 times before success
[ 289.771565][ T134] clocksource_wdtest: --- Watchdog with 4x error injection, 3 retries, expect clock skew.
[ 290.253068][ C0] clocksource: timekeeping watchdog on CPU0: kvm-clock read-back delay of 400641ns, attempt 4, marking unstable
[ 290.254315][ C0] clocksource_wdtest: --- Marking wdtest-ktime unstable due to clocksource watchdog.
[ 291.961481][ T134] clocksource: wdtest-ktime: mask: 0xffffffffffffffff max_cycles: 0x1cd42e4dffb, max_idle_ns: 881590591483 ns
[ 291.962591][ T134] clocksource_wdtest: --- Watchdog clock-value-fuzz error injection, expect clock skew and per-CPU mismatches.
[ 292.981464][ C1] clocksource: timekeeping watchdog on CPU1: Marking clocksource 'wdtest-ktime' as unstable because the skew is too large:
[ 292.982750][ C1] clocksource: 'kvm-clock' wd_nsec: 510005748 wd_now: 4883ee4a9c wd_last: 48658838a8 mask: ffffffffffffffff
[ 292.984061][ C1] clocksource: 'wdtest-ktime' cs_nsec: 710005793 cs_now: 16b5eaa8dd01c7f0 cs_last: 16b5eaa8b2aff3cf mask: ffffffffffffffff
[ 292.985398][ C1] clocksource: 'kvm-clock' (not 'wdtest-ktime') is current clocksource.
[ 292.986400][ C1] clocksource_wdtest: --- Marking wdtest-ktime unstable due to clocksource watchdog.
[ 294.011479][ T134] clocksource: Checking clocksource wdtest-ktime synchronization from CPU 0 to CPUs 1.
[ 294.012604][ T134] clocksource: CPUs 1 ahead of CPU 0 for clocksource wdtest-ktime.
[ 294.013477][ T134] clocksource: CPU 0 check durations 25152ns - 25152ns for clocksource wdtest-ktime.
[ 294.014480][ T134] clocksource_wdtest: --- Done with test.
[ 297.368551][ T464] sysrq: Emergency Sync
[ 297.369361][ T12] Emergency Sync complete
[ 297.369902][ T464] sysrq: Resetting
Kboot worker: lkp-worker53
Elapsed time: 360
kvm=(
qemu-system-i386
-enable-kvm
-cpu SandyBridge
-kernel $kernel
-initrd initrd-vm-snb-i386-127.cgz
-m 4096
-smp 2
-device e1000,netdev=net0
-netdev user,id=net0,hostfwd=tcp::32032-:22
-boot order=nc
-no-reboot
-watchdog i6300esb
-watchdog-action debug
-rtc base=localtime
-serial stdio
-display none
-monitor null
)
append=(
ip=::::vm-snb-i386-127::dhcp
root=/dev/ram0
user=lkp
job=/job-script
ARCH=i386
kconfig=i386-randconfig-a004-20211104
branch=linus/master
commit=1d1bb12a8b1805ddeef9793ebeb920179fb0fa38
BOOT_IMAGE=/pkg/linux/i386-randconfig-a004-20211104/gcc-9/1d1bb12a8b1805ddeef9793ebeb920179fb0fa38/vmlinuz-5.14.0-rc1-g1d1bb12a8b18
vmalloc=128M
initramfs_async=0
page_owner=on
max_uptime=600
RESULT_ROOT=/result/boot/1/vm-snb-i386/yocto-i386-minimal-20190520.cgz/i386-randconfig-a004-20211104/gcc-9/1d1bb12a8b1805ddeef9793ebeb920179fb0fa38/21
result_service=tmpfs
selinux=0
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
net.ifnames=0
printk.devkmsg=on
panic=-1
softlockup_panic=1
nmi_watchdog=panic
oops=panic
load_ramdisk=2
prompt_ramdisk=0
drbd.minor_count=8
systemd.log_level=err
ignore_loglevel
console=tty0
earlyprintk=ttyS0,115200
console=ttyS0,115200
vga=normal
rw
rcuperf.shutdown=0
watchdog_thresh=240
)
"${kvm[@]}" -append "${append[*]}"
To reproduce:
# build kernel
cd linux
cp config-5.14.0-rc1-g1d1bb12a8b18 .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=i386 olddefconfig prepare modules_prepare bzImage
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
6 months, 1 week
[block] 900e080752: WARNING:at_block/mq-deadline.c:#dd_exit_sched
by kernel test robot
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 900e080752025f0016128f07c9ed4c50eba3654b ("block: move queue enter logic into blk_mq_submit_bio()")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master
in testcase: blktests
version: blktests-x86_64-3be7849-1_20211102
with following parameters:
disk: 1SSD
test: block-group-15
ucode: 0xe2
on test machine: 4 threads Intel(R) Core(TM) i5-6500 CPU @ 3.20GHz with 32G memory
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang(a)intel.com>
[ 54.150952][ T1244] WARNING: CPU: 0 PID: 1244 at block/mq-deadline.c:597 dd_exit_sched (block/mq-deadline.c:597 (discriminator 3))
[ 54.160432][ T1244] Modules linked in: null_blk loop dm_multipath dm_mod btrfs blake2b_generic ipmi_devintf xor ipmi_msghandler zstd_compress raid6_pq libcrc32c sd_mod t10_pi sg intel_rapl_msr intel_rapl_common x86_pkg_temp_thermal intel_powerclamp coretemp i915 kvm_intel intel_gtt ttm kvm drm_kms_helper irqbypass crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel syscopyarea mei_wdt sysfillrect sysimgblt wmi_bmof fb_sys_fops rapl mei_me ahci libahci intel_cstate joydev intel_uncore libata mei drm intel_pch_thermal wmi intel_pmc_core video acpi_pad ip_tables [last unloaded: null_blk]
[ 54.215755][ T1244] CPU: 0 PID: 1244 Comm: rmdir Tainted: G I 5.15.0-rc6-00186-g900e08075202 #1
[ 54.226404][ T1244] Hardware name: Dell Inc. OptiPlex 7040/0Y7WYT, BIOS 1.1.1 10/07/2015
[ 54.235254][ T1244] RIP: 0010:dd_exit_sched (block/mq-deadline.c:597 (discriminator 3))
[ 54.241191][ T1244] Code: fb 1a 7f 01 00 75 d7 44 8b 0e 8b 4b 34 44 89 ee 48 c7 c7 f8 93 58 82 8b 53 30 44 8b 43 38 c6 05 db 1a 7f 01 01 e8 93 e5 66 00 <0f> 0b eb b0 0f 0b eb 85 66 66 2e 0f 1f 84 00 00 00 00 00 66 66 2e
All code
========
0: fb sti
1: 1a 7f 01 sbb 0x1(%rdi),%bh
4: 00 75 d7 add %dh,-0x29(%rbp)
7: 44 8b 0e mov (%rsi),%r9d
a: 8b 4b 34 mov 0x34(%rbx),%ecx
d: 44 89 ee mov %r13d,%esi
10: 48 c7 c7 f8 93 58 82 mov $0xffffffff825893f8,%rdi
17: 8b 53 30 mov 0x30(%rbx),%edx
1a: 44 8b 43 38 mov 0x38(%rbx),%r8d
1e: c6 05 db 1a 7f 01 01 movb $0x1,0x17f1adb(%rip) # 0x17f1b00
25: e8 93 e5 66 00 callq 0x66e5bd
2a:* 0f 0b ud2 <-- trapping instruction
2c: eb b0 jmp 0xffffffffffffffde
2e: 0f 0b ud2
30: eb 85 jmp 0xffffffffffffffb7
32: 66 66 2e 0f 1f 84 00 data16 nopw %cs:0x0(%rax,%rax,1)
39: 00 00 00 00
3d: 66 data16
3e: 66 data16
3f: 2e cs
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: eb b0 jmp 0xffffffffffffffb4
4: 0f 0b ud2
6: eb 85 jmp 0xffffffffffffff8d
8: 66 66 2e 0f 1f 84 00 data16 nopw %cs:0x0(%rax,%rax,1)
f: 00 00 00 00
13: 66 data16
14: 66 data16
15: 2e cs
[ 54.262191][ T1244] RSP: 0018:ffffc900015d7cf8 EFLAGS: 00010282
[ 54.268943][ T1244] RAX: 0000000000000000 RBX: ffff888100db5e80 RCX: 0000000000000000
[ 54.277522][ T1244] RDX: ffff88882d8239c0 RSI: ffff88882d817b50 RDI: ffff88882d817b50
[ 54.286134][ T1244] RBP: ffff888100db5e00 R08: ffff88882d817b50 R09: ffffc900015d7b18
[ 54.294703][ T1244] R10: 0000000000000001 R11: 0000000000000001 R12: ffff888100db5f48
[ 54.303441][ T1244] R13: 0000000000000001 R14: 0000000000000000 R15: 0000000000000000
[ 54.312119][ T1244] FS: 00007f9323c47540(0000) GS:ffff88882d800000(0000) knlGS:0000000000000000
[ 54.321650][ T1244] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 54.328904][ T1244] CR2: 00007f93238f0e74 CR3: 000000086d350005 CR4: 00000000003706f0
[ 54.337490][ T1244] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 54.346189][ T1244] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 54.354824][ T1244] Call Trace:
[ 54.358927][ T1244] blk_mq_exit_sched (block/blk-mq-sched.c:681)
[ 54.364353][ T1244] __elevator_exit (block/elevator.c:195)
[ 54.369581][ T1244] blk_release_queue (block/blk-sysfs.c:758 block/blk-sysfs.c:804)
[ 54.375185][ T1244] kobject_release (lib/kobject.c:709 lib/kobject.c:736)
[ 54.380764][ T1244] disk_release (block/genhd.c:1109 (discriminator 3))
[ 54.385778][ T1244] device_release (drivers/base/core.c:2236)
[ 54.390961][ T1244] kobject_release (lib/kobject.c:709 lib/kobject.c:736)
[ 54.396369][ T1244] null_del_dev+0x63/0x140 null_blk
[ 54.403141][ T1244] nullb_group_drop_item (drivers/block/null_blk/main.c:535) null_blk
[ 54.409989][ T1244] configfs_rmdir (fs/configfs/dir.c:1527)
[ 54.415392][ T1244] ? make_kgid (kernel/user_namespace.c:463)
[ 54.420390][ T1244] vfs_rmdir (fs/namei.c:3970 fs/namei.c:3948)
[ 54.425247][ T1244] do_rmdir (fs/namei.c:4032)
[ 54.430202][ T1244] __x64_sys_rmdir (fs/namei.c:4051 fs/namei.c:4049 fs/namei.c:4049)
[ 54.435455][ T1244] do_syscall_64 (arch/x86/entry/common.c:50 arch/x86/entry/common.c:80)
[ 54.440502][ T1244] entry_SYSCALL_64_after_hwframe (arch/x86/entry/entry_64.S:113)
[ 54.447122][ T1244] RIP: 0033:0x7f9323b71027
[ 54.452161][ T1244] Code: 73 01 c3 48 8b 0d 69 ee 0c 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 b8 54 00 00 00 0f 05 <48> 3d 01 f0 ff ff 73 01 c3 48 8b 0d 39 ee 0c 00 f7 d8 64 89 01 48
All code
========
0: 73 01 jae 0x3
2: c3 retq
3: 48 8b 0d 69 ee 0c 00 mov 0xcee69(%rip),%rcx # 0xcee73
a: f7 d8 neg %eax
c: 64 89 01 mov %eax,%fs:(%rcx)
f: 48 83 c8 ff or $0xffffffffffffffff,%rax
13: c3 retq
14: 66 2e 0f 1f 84 00 00 nopw %cs:0x0(%rax,%rax,1)
1b: 00 00 00
1e: 0f 1f 44 00 00 nopl 0x0(%rax,%rax,1)
23: b8 54 00 00 00 mov $0x54,%eax
28: 0f 05 syscall
2a:* 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax <-- trapping instruction
30: 73 01 jae 0x33
32: c3 retq
33: 48 8b 0d 39 ee 0c 00 mov 0xcee39(%rip),%rcx # 0xcee73
3a: f7 d8 neg %eax
3c: 64 89 01 mov %eax,%fs:(%rcx)
3f: 48 rex.W
Code starting with the faulting instruction
===========================================
0: 48 3d 01 f0 ff ff cmp $0xfffffffffffff001,%rax
6: 73 01 jae 0x9
8: c3 retq
9: 48 8b 0d 39 ee 0c 00 mov 0xcee39(%rip),%rcx # 0xcee49
10: f7 d8 neg %eax
12: 64 89 01 mov %eax,%fs:(%rcx)
15: 48 rex.W
[ 54.473215][ T1244] RSP: 002b:00007ffd6af73e18 EFLAGS: 00000206 ORIG_RAX: 0000000000000054
[ 54.482441][ T1244] RAX: ffffffffffffffda RBX: 00007ffd6af74a24 RCX: 00007f9323b71027
[ 54.491083][ T1244] RDX: 00007f9323c43000 RSI: 0000000000000001 RDI: 00007ffd6af74a24
[ 54.499651][ T1244] RBP: 00007ffd6af73f48 R08: 0000000000000000 R09: 0000000000000000
[ 54.508417][ T1244] R10: fffffffffffffb94 R11: 0000000000000206 R12: 0000000000000002
[ 54.516988][ T1244] R13: 00007ffd6af73f40 R14: 0000000000000000 R15: 000055a258d020c7
[ 54.525536][ T1244] ---[ end trace 054b3b27794cc243 ]---
[ 54.571821][ T319] block/031 (do IO on null-blk with a host tag set) [failed]
[ 54.571824][ T319]
[ 54.584318][ T319] runtime ... 30.970s
[ 54.584320][ T319]
[ 54.593005][ T319] something found in dmesg:
[ 54.593007][ T319]
[ 54.603118][ T319]
[ 23.577249] run blktests block/031 at 2021-11-07 22:15:55
[ 54.603120][ T319]
[ 54.615404][ T319]
[ 23.592594] null_blk: module loaded
[ 54.615405][ T319]
[ 54.632273][ T319]
[ 26.450501] result_service: raw_upload, RESULT_MNT: /internal-lkp-server/result, RESULT_ROOT: /internal-lkp-server/result/blktests/1SSD-block-group-15-ucode=0xe2/lkp-skl-d04/debian-10.4-x86_64-20200603.cgz/x86_64-rhel-8.3-func/gcc-9/900e080752025f0016128f07c9ed4c50eba3654b/5, TMP_RESULT_ROOT: /tmp/lkp/result
[ 54.632276][ T319]
[ 54.667595][ T319]
[ 54.667596][ T319]
[ 54.678070][ T319]
[ 26.486062] run-job /lkp/jobs/scheduled/lkp-skl-d04/blktests-1SSD-block-group-15-ucode=0xe2-debian-10.4-x86_64-20200603.cgz-900e080752025f0016128f07c9ed4c50eba3654b-20211108-67459-gvgohg-3.yaml
[ 54.678072][ T319]
[ 54.702246][ T319]
[ 54.702247][ T319]
[ 55.072171][ T319]
[ 27.554517] /usr/bin/wget -q --timeout=1800 --tries=1 --local-encoding=UTF-8 http://internal-lkp-server:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_fil... -O /dev/null
[ 55.072176][ T319]
[ 55.111161][ T319]
[ 55.111162][ T319]
[ 55.118160][ T319]
[ 27.591405] target ucode: 0xe2
[ 55.118161][ T319]
[ 55.127416][ T319]
[ 55.127417][ T319]
[ 55.133679][ T319] ...
[ 55.133681][ T319]
[ 55.141849][ T319] (See '/lkp/benchmarks/blktests/results/nodev/block/031.dmesg' for the entire message)
[ 55.141850][ T319]
[ 55.163542][ T319] /usr/bin/wget -q --timeout=1800 --tries=1 --local-encoding=UTF-8 http://internal-lkp-server:80/~lkp/cgi-bin/lkp-jobfile-append-var?job_fil... -O /dev/null
[ 55.163544][ T319]
[ 56.132208][ T319] kill 872 vmstat --timestamp -n 10
[ 56.132211][ T319]
[ 56.141884][ T319] kill 870 dmesg --follow --decode
[ 56.141885][ T319]
[ 56.151832][ T319] wait for background processes: 875 878 meminfo oom-killer
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
sudo bin/lkp install job.yaml # job file is attached in this email
bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run
sudo bin/lkp run generated-yaml-file
# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.
---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation
Thanks,
Oliver Sang
6 months, 1 week
