mirror of
https://github.com/torvalds/linux.git
synced 2024-11-10 22:21:40 +00:00
2b44760609
Running the following two commands in parallel on a multi-processor
AArch64 machine can sporadically produce an unexpected warning about
duplicate histogram entries:
$ while true; do
echo hist:key=id.syscall:val=hitcount > \
/sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/trigger
cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
sleep 0.001
done
$ stress-ng --sysbadaddr $(nproc)
The warning looks as follows:
[ 2911.172474] ------------[ cut here ]------------
[ 2911.173111] Duplicates detected: 1
[ 2911.173574] WARNING: CPU: 2 PID: 12247 at kernel/trace/tracing_map.c:983 tracing_map_sort_entries+0x3e0/0x408
[ 2911.174702] Modules linked in: iscsi_ibft(E) iscsi_boot_sysfs(E) rfkill(E) af_packet(E) nls_iso8859_1(E) nls_cp437(E) vfat(E) fat(E) ena(E) tiny_power_button(E) qemu_fw_cfg(E) button(E) fuse(E) efi_pstore(E) ip_tables(E) x_tables(E) xfs(E) libcrc32c(E) aes_ce_blk(E) aes_ce_cipher(E) crct10dif_ce(E) polyval_ce(E) polyval_generic(E) ghash_ce(E) gf128mul(E) sm4_ce_gcm(E) sm4_ce_ccm(E) sm4_ce(E) sm4_ce_cipher(E) sm4(E) sm3_ce(E) sm3(E) sha3_ce(E) sha512_ce(E) sha512_arm64(E) sha2_ce(E) sha256_arm64(E) nvme(E) sha1_ce(E) nvme_core(E) nvme_auth(E) t10_pi(E) sg(E) scsi_mod(E) scsi_common(E) efivarfs(E)
[ 2911.174738] Unloaded tainted modules: cppc_cpufreq(E):1
[ 2911.180985] CPU: 2 PID: 12247 Comm: cat Kdump: loaded Tainted: G E 6.7.0-default #2 1b58bbb22c97e4399dc09f92d309344f69c44a01
[ 2911.182398] Hardware name: Amazon EC2 c7g.8xlarge/, BIOS 1.0 11/1/2018
[ 2911.183208] pstate: 61400005 (nZCv daif +PAN -UAO -TCO +DIT -SSBS BTYPE=--)
[ 2911.184038] pc : tracing_map_sort_entries+0x3e0/0x408
[ 2911.184667] lr : tracing_map_sort_entries+0x3e0/0x408
[ 2911.185310] sp : ffff8000a1513900
[ 2911.185750] x29: ffff8000a1513900 x28: ffff0003f272fe80 x27: 0000000000000001
[ 2911.186600] x26: ffff0003f272fe80 x25: 0000000000000030 x24: 0000000000000008
[ 2911.187458] x23: ffff0003c5788000 x22: ffff0003c16710c8 x21: ffff80008017f180
[ 2911.188310] x20: ffff80008017f000 x19: ffff80008017f180 x18: ffffffffffffffff
[ 2911.189160] x17: 0000000000000000 x16: 0000000000000000 x15: ffff8000a15134b8
[ 2911.190015] x14: 0000000000000000 x13: 205d373432323154 x12: 5b5d313131333731
[ 2911.190844] x11: 00000000fffeffff x10: 00000000fffeffff x9 : ffffd1b78274a13c
[ 2911.191716] x8 : 000000000017ffe8 x7 : c0000000fffeffff x6 : 000000000057ffa8
[ 2911.192554] x5 : ffff0012f6c24ec0 x4 : 0000000000000000 x3 : ffff2e5b72b5d000
[ 2911.193404] x2 : 0000000000000000 x1 : 0000000000000000 x0 : ffff0003ff254480
[ 2911.194259] Call trace:
[ 2911.194626] tracing_map_sort_entries+0x3e0/0x408
[ 2911.195220] hist_show+0x124/0x800
[ 2911.195692] seq_read_iter+0x1d4/0x4e8
[ 2911.196193] seq_read+0xe8/0x138
[ 2911.196638] vfs_read+0xc8/0x300
[ 2911.197078] ksys_read+0x70/0x108
[ 2911.197534] __arm64_sys_read+0x24/0x38
[ 2911.198046] invoke_syscall+0x78/0x108
[ 2911.198553] el0_svc_common.constprop.0+0xd0/0xf8
[ 2911.199157] do_el0_svc+0x28/0x40
[ 2911.199613] el0_svc+0x40/0x178
[ 2911.200048] el0t_64_sync_handler+0x13c/0x158
[ 2911.200621] el0t_64_sync+0x1a8/0x1b0
[ 2911.201115] ---[ end trace 0000000000000000 ]---
The problem appears to be caused by CPU reordering of writes issued from
__tracing_map_insert().
The check for the presence of an element with a given key in this
function is:
val = READ_ONCE(entry->val);
if (val && keys_match(key, val->key, map->key_size)) ...
The write of a new entry is:
elt = get_free_elt(map);
memcpy(elt->key, key, map->key_size);
entry->val = elt;
The "memcpy(elt->key, key, map->key_size);" and "entry->val = elt;"
stores may become visible in the reversed order on another CPU. This
second CPU might then incorrectly determine that a new key doesn't match
an already present val->key and subsequently insert a new element,
resulting in a duplicate.
Fix the problem by adding a write barrier between
"memcpy(elt->key, key, map->key_size);" and "entry->val = elt;", and for
good measure, also use WRITE_ONCE(entry->val, elt) for publishing the
element. The sequence pairs with the mentioned "READ_ONCE(entry->val);"
and the "val->key" check which has an address dependency.
The barrier is placed on a path executed when adding an element for
a new key. Subsequent updates targeting the same key remain unaffected.
From the user's perspective, the issue was introduced by commit
|
||
|---|---|---|
| .. | ||
| rv | ||
| blktrace.c | ||
| bpf_trace.c | ||
| bpf_trace.h | ||
| error_report-traces.c | ||
| fgraph.c | ||
| fprobe.c | ||
| ftrace_internal.h | ||
| ftrace.c | ||
| Kconfig | ||
| kprobe_event_gen_test.c | ||
| Makefile | ||
| pid_list.c | ||
| pid_list.h | ||
| power-traces.c | ||
| preemptirq_delay_test.c | ||
| rethook.c | ||
| ring_buffer_benchmark.c | ||
| ring_buffer.c | ||
| rpm-traces.c | ||
| synth_event_gen_test.c | ||
| trace_benchmark.c | ||
| trace_benchmark.h | ||
| trace_boot.c | ||
| trace_branch.c | ||
| trace_btf.c | ||
| trace_btf.h | ||
| trace_clock.c | ||
| trace_dynevent.c | ||
| trace_dynevent.h | ||
| trace_entries.h | ||
| trace_eprobe.c | ||
| trace_event_perf.c | ||
| trace_events_filter_test.h | ||
| trace_events_filter.c | ||
| trace_events_hist.c | ||
| trace_events_inject.c | ||
| trace_events_synth.c | ||
| trace_events_trigger.c | ||
| trace_events_user.c | ||
| trace_events.c | ||
| trace_export.c | ||
| trace_fprobe.c | ||
| trace_functions_graph.c | ||
| trace_functions.c | ||
| trace_hwlat.c | ||
| trace_irqsoff.c | ||
| trace_kdb.c | ||
| trace_kprobe_selftest.c | ||
| trace_kprobe_selftest.h | ||
| trace_kprobe.c | ||
| trace_mmiotrace.c | ||
| trace_nop.c | ||
| trace_osnoise.c | ||
| trace_output.c | ||
| trace_output.h | ||
| trace_preemptirq.c | ||
| trace_printk.c | ||
| trace_probe_kernel.h | ||
| trace_probe_tmpl.h | ||
| trace_probe.c | ||
| trace_probe.h | ||
| trace_recursion_record.c | ||
| trace_sched_switch.c | ||
| trace_sched_wakeup.c | ||
| trace_selftest_dynamic.c | ||
| trace_selftest.c | ||
| trace_seq.c | ||
| trace_stack.c | ||
| trace_stat.c | ||
| trace_stat.h | ||
| trace_synth.h | ||
| trace_syscalls.c | ||
| trace_uprobe.c | ||
| trace.c | ||
| trace.h | ||
| tracing_map.c | ||
| tracing_map.h | ||