[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20210227141646.GC22871@xsang-OptiPlex-9020>
Date: Sat, 27 Feb 2021 22:16:46 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Steven Rostedt <rostedt@...dmis.org>
Cc: 0day robot <lkp@...el.com>, LKML <linux-kernel@...r.kernel.org>,
lkp@...ts.01.org, Ingo Molnar <mingo@...nel.org>,
Andrew Morton <akpm@...ux-foundation.org>,
Masami Hiramatsu <mhiramat@...nel.org>,
Linus Torvalds <torvalds@...ux-foundation.org>,
Jacob Wen <jian.w.wen@...cle.com>
Subject: [tracing] 5c71984c21:
WARNING:at_kernel/trace/trace_events.c:#test_event_printk
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 5c71984c2178ced437bc855dd09a9dd268b756c4 ("[PATCH 1/2] tracing: Add check of trace event print fmts for dereferencing pointers")
url: https://github.com/0day-ci/linux/commits/Steven-Rostedt/tracing-Detect-unsafe-dereferencing-of-pointers-from-trace-events/20210227-030901
base: https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git 8b83369ddcb3fb9cab5c1088987ce477565bb630
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 8G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-----------------------------------------------------------+------------+------------+
| | 8b83369ddc | 5c71984c21 |
+-----------------------------------------------------------+------------+------------+
| boot_successes | 6 | 0 |
| boot_failures | 0 | 6 |
| WARNING:at_kernel/trace/trace_events.c:#test_event_printk | 0 | 6 |
| EIP:test_event_printk | 0 | 6 |
+-----------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@...el.com>
[ 1.360022] WARNING: CPU: 0 PID: 0 at kernel/trace/trace_events.c:404 test_event_printk (kbuild/src/consumer/kernel/trace/trace_events.c:404 (discriminator 1))
[ 1.361410] Modules linked in:
[ 1.361889] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.11.0-11483-g5c71984c2178 #2
[ 1.363072] EIP: test_event_printk (kbuild/src/consumer/kernel/trace/trace_events.c:404 (discriminator 1))
[ 1.363753] Code: 01 66 90 0f 88 57 03 00 00 83 c3 01 89 5d ec 8b 45 f0 0f b6 04 18 84 c0 75 c1 8b 75 d8 8b 7d dc 89 f8 09 f0 0f 84 6f ff ff ff <0f> 0b 89 f0 83 e0 01 0f 85 c5 d9 f2 00 0f ac fe 01 d1 ef 83 c0 01
All code
========
0: 01 66 90 add %esp,-0x70(%rsi)
3: 0f 88 57 03 00 00 js 0x360
9: 83 c3 01 add $0x1,%ebx
c: 89 5d ec mov %ebx,-0x14(%rbp)
f: 8b 45 f0 mov -0x10(%rbp),%eax
12: 0f b6 04 18 movzbl (%rax,%rbx,1),%eax
16: 84 c0 test %al,%al
18: 75 c1 jne 0xffffffffffffffdb
1a: 8b 75 d8 mov -0x28(%rbp),%esi
1d: 8b 7d dc mov -0x24(%rbp),%edi
20: 89 f8 mov %edi,%eax
22: 09 f0 or %esi,%eax
24: 0f 84 6f ff ff ff je 0xffffffffffffff99
2a:* 0f 0b ud2 <-- trapping instruction
2c: 89 f0 mov %esi,%eax
2e: 83 e0 01 and $0x1,%eax
31: 0f 85 c5 d9 f2 00 jne 0xf2d9fc
37: 0f ac fe 01 shrd $0x1,%edi,%esi
3b: d1 ef shr %edi
3d: 83 c0 01 add $0x1,%eax
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 89 f0 mov %esi,%eax
4: 83 e0 01 and $0x1,%eax
7: 0f 85 c5 d9 f2 00 jne 0xf2d9d2
d: 0f ac fe 01 shrd $0x1,%edi,%esi
11: d1 ef shr %edi
13: 83 c0 01 add $0x1,%eax
[ 1.366646] EAX: 00000008 EBX: 0000006c ECX: 00000004 EDX: 00000000
[ 1.367616] ESI: 00000008 EDI: 00000000 EBP: 82ab5f3c ESP: 82ab5ef4
[ 1.368594] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00210002
[ 1.369643] CR0: 80050033 CR2: ffbff000 CR3: 0347f000 CR4: 000406b0
[ 1.370612] Call Trace:
[ 1.370997] ? up_write (kbuild/src/consumer/kernel/locking/rwsem.c:1321 kbuild/src/consumer/kernel/locking/rwsem.c:1459)
[ 1.371555] trace_event_raw_init (kbuild/src/consumer/kernel/trace/trace_events.c:426)
[ 1.372220] event_init (kbuild/src/consumer/kernel/trace/trace_events.c:2498)
[ 1.372738] ? trace_event_init (kbuild/src/consumer/include/linux/list.h:282 kbuild/src/consumer/kernel/trace/trace.h:388 kbuild/src/consumer/kernel/trace/trace_events.c:3592 kbuild/src/consumer/kernel/trace/trace_events.c:3697)
[ 1.373375] trace_event_init (kbuild/src/consumer/kernel/trace/trace_events.c:3603 kbuild/src/consumer/kernel/trace/trace_events.c:3697)
[ 1.373986] trace_init (kbuild/src/consumer/kernel/trace/trace.c:9701)
[ 1.374476] start_kernel (kbuild/src/consumer/init/main.c:949 (discriminator 11))
[ 1.375049] i386_start_kernel (kbuild/src/consumer/arch/x86/kernel/head32.c:57)
[ 1.375658] startup_32_smp (kbuild/src/consumer/arch/x86/kernel/head_32.S:328)
[ 1.376278] irq event stamp: 0
[ 1.376754] hardirqs last enabled at (0): 0x0
[ 1.377613] hardirqs last disabled at (0): 0x0
[ 1.378471] softirqs last enabled at (0): 0x0
[ 1.379329] softirqs last disabled at (0): 0x0
[ 1.380202] ---[ end trace 7c274a1c59fae664 ]---
[ 1.380914] event rdev_reset_tid_config has unsafe dereference of argument 3
[ 1.381998] print_fmt: "%s, netdev:%s(%d), peer: %pM, tids: 0x%x", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer), REC->tids
[ 1.383843] event rdev_set_tid_config has unsafe dereference of argument 3
[ 1.384913] print_fmt: "%s, netdev:%s(%d), peer: %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer)
[ 1.386434] event rdev_probe_mesh_link has unsafe dereference of argument 3
[ 1.387507] print_fmt: "%s, netdev:%s(%d), %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->dest)
[ 1.388962] event cfg80211_update_owe_info_event has unsafe dereference of argument 3
[ 1.390168] print_fmt: "%s, netdev:%s(%d), peer: %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer)
[ 1.391688] event rdev_update_owe_info has unsafe dereference of argument 3
[ 1.392773] print_fmt: "%s, netdev:%s(%d), peer: %pM status %d", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer), REC->status
[ 1.394602] event cfg80211_pmsr_report has unsafe dereference of argument 3
[ 1.395677] print_fmt: "%s, wdev(%u), cookie:%lld, %pM", REC->wiphy_name, (REC->id), (unsigned long long)REC->cookie, (REC->addr)
[ 1.397489] event cfg80211_ft_event has unsafe dereference of argument 3
[ 1.398526] print_fmt: "%s, netdev:%s(%d), target_ap: %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->target_ap)
[ 1.400200] event cfg80211_return_bss has unsafe dereference of argument 0
[ 1.401265] print_fmt: "%pM, band: %d, freq: %u.%03u", (REC->bssid), REC->band, REC->center_freq, REC->freq_offset
[ 1.402868] event cfg80211_inform_bss_frame has unsafe dereference of argument 8
[ 1.404016] print_fmt: "%s, band: %d, freq: %u.%03u(scan_width: %d) signal: %d, tsb:%llu, detect_tsf:%llu, tsf_bssid: %pM", REC->wiphy_name, REC->band, REC->center_freq, REC->freq_offset, REC->scan_width, REC->signal, (unsigned long long)REC->ts_boottime, (unsigned long long)REC->parent_tsf, (REC->parent_bssid)
[ 1.408277] event cfg80211_get_bss has unsafe dereference of argument 4
[ 1.409297] print_fmt: "%s, band: %d, freq: %u.%03u, %pM, buf: %#.2x, bss_type: %d, privacy: %d", REC->wiphy_name, REC->band, REC->center_freq, REC->freq_offset, (REC->bssid), ((u8 *)__get_dynamic_array(ssid))[0], REC->bss_type, REC->privacy
[ 1.412593] event cfg80211_scan_done has unsafe dereference of argument 2
[ 1.413682] print_fmt: "aborted: %s, scan start (TSF): %llu, tsf_bssid: %pM", (REC->aborted) ? "true" : "false", (unsigned long long)REC->scan_start_tsf, (REC->tsf_bssid)
[ 1.416032] event cfg80211_tdls_oper_request has unsafe dereference of argument 3
[ 1.417182] print_fmt: "%s, netdev:%s(%d), peer: %pM, oper: %d, reason_code %u", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer), REC->oper, REC->reason_code
[ 1.419435] event cfg80211_pmksa_candidate_notify has unsafe dereference of argument 3
[ 1.420664] print_fmt: "netdev:%s(%d), index:%d, bssid: %pM, pre auth: %s", REC->name, REC->ifindex, REC->index, (REC->bssid), (REC->preauth) ? "true" : "false"
[ 1.422874] event cfg80211_gtk_rekey_notify has unsafe dereference of argument 2
[ 1.424019] print_fmt: "netdev:%s(%d), mac: %pM", REC->name, REC->ifindex, (REC->macaddr)
[ 1.425285] event cfg80211_cqm_pktloss_notify has unsafe dereference of argument 2
[ 1.426451] print_fmt: "netdev:%s(%d), peer: %pM, num of lost packets: %u", REC->name, REC->ifindex, (REC->peer), REC->num_packets
[ 1.428267] event cfg80211_probe_status has unsafe dereference of argument 2
[ 1.429352] print_fmt: "netdev:%s(%d) addr:%pM, cookie: %llu, acked: %s", REC->name, REC->ifindex, (REC->addr), REC->cookie, (REC->acked) ? "true" : "false"
[ 1.431507] event cfg80211_ibss_joined has unsafe dereference of argument 2
[ 1.432591] print_fmt: "netdev:%s(%d), bssid: %pM, band: %d, freq: %u.%03u", REC->name, REC->ifindex, (REC->bssid), REC->band, REC->center_freq, REC->freq_offset
[ 1.434814] event cfg80211_rx_unexpected_4addr_frame has unsafe dereference of argument 2
[ 1.436080] print_fmt: "netdev:%s(%d), %pM", REC->name, REC->ifindex, (REC->addr)
[ 1.437237] event cfg80211_rx_spurious_frame has unsafe dereference of argument 2
[ 1.438397] print_fmt: "netdev:%s(%d), %pM", REC->name, REC->ifindex, (REC->addr)
[ 1.439576] event cfg80211_rx_control_port has unsafe dereference of argument 3
[ 1.440718] print_fmt: "netdev:%s(%d), len=%d, %pM, proto: 0x%x, unencrypted: %s", REC->name, REC->ifindex, REC->len, (REC->from), REC->proto, (REC->unencrypted) ? "true" : "false"
[ 1.443201] event cfg80211_del_sta has unsafe dereference of argument 2
[ 1.444230] print_fmt: "netdev:%s(%d), mac: %pM", REC->name, REC->ifindex, (REC->macaddr)
[ 1.445507] event cfg80211_new_sta has unsafe dereference of argument 2
[ 1.446528] print_fmt: "netdev:%s(%d), %pM", REC->name, REC->ifindex, (REC->mac_addr)
[ 1.447753] event cfg80211_michael_mic_failure has unsafe dereference of argument 2
[ 1.448942] print_fmt: "netdev:%s(%d), %pM, key type: %d, key id: %d, tsc: %pm", REC->name, REC->ifindex, (REC->addr), REC->key_type, REC->key_id, REC->tsc
[ 1.451088] event cfg80211_send_assoc_timeout has unsafe dereference of argument 2
[ 1.452264] print_fmt: "netdev:%s(%d), mac: %pM", REC->name, REC->ifindex, (REC->mac)
[ 1.453478] event cfg80211_send_auth_timeout has unsafe dereference of argument 2
[ 1.454627] print_fmt: "netdev:%s(%d), mac: %pM", REC->name, REC->ifindex, (REC->mac)
[ 1.455843] event cfg80211_send_rx_assoc has unsafe dereference of argument 2
[ 1.456949] print_fmt: "netdev:%s(%d), %pM, band: %d, freq: %u.%03u", REC->name, REC->ifindex, (REC->bssid), REC->band, REC->center_freq, REC->freq_offset
[ 1.459087] event cfg80211_notify_new_peer_candidate has unsafe dereference of argument 2
[ 1.460354] print_fmt: "netdev:%s(%d), mac: %pM", REC->name, REC->ifindex, (REC->macaddr)
[ 1.461650] event rdev_del_pmk has unsafe dereference of argument 3
[ 1.462630] print_fmt: "%s, netdev:%s(%d), %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->aa)
[ 1.464056] event rdev_set_pmk has unsafe dereference of argument 3
[ 1.465024] print_fmt: "%s, netdev:%s(%d), %pMpmk_len=%u, pmk: %s pmk_r0_name: %s", REC->wiphy_name, REC->name, REC->ifindex, (REC->aa), REC->pmk_len, __print_array(__get_dynamic_array(pmk), __get_dynamic_array_len(pmk), 1), REC->pmk_r0_name_len ? __print_array(__get_dynamic_array(pmk_r0_name), __get_dynamic_array_len(pmk_r0_name), 1) : ""
[ 1.469665] event rdev_tdls_cancel_channel_switch has unsafe dereference of argument 3
[ 1.470891] print_fmt: "%s, netdev:%s(%d), %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->addr)
[ 1.472341] event rdev_tdls_channel_switch has unsafe dereference of argument 3
[ 1.473467] print_fmt: "%s, netdev:%s(%d), %pM oper class %d, band: %d, control freq: %u.%03u, width: %d, cf1: %u.%03u, cf2: %u", REC->wiphy_name, REC->name, REC->ifindex, (REC->addr), REC->oper_class, REC->band, REC->control_freq, REC->freq_offset, REC->width, REC->center_freq1, REC->freq1_offset, REC->center_freq2
[ 1.477783] event rdev_del_tx_ts has unsafe dereference of argument 3
[ 1.478782] print_fmt: "%s, netdev:%s(%d), %pM, TSID %d", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer), REC->tsid
[ 1.480504] event rdev_add_tx_ts has unsafe dereference of argument 3
[ 1.481497] print_fmt: "%s, netdev:%s(%d), %pM, TSID %d, UP %d, time %d", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer), REC->tsid, REC->user_prio, REC->admitted_time
[ 1.483933] event rdev_tx_control_port has unsafe dereference of argument 3
[ 1.485021] print_fmt: "%s, netdev:%s(%d), %pM, proto: 0x%x, unencrypted: %s", REC->wiphy_name, REC->name, REC->ifindex, (REC->dest), (__u16)__builtin_bswap16((__u16)(( __u16)(__be16)(REC->proto))), (REC->unencrypted) ? "true" : "false"
[ 1.488264] event rdev_del_pmksa has unsafe dereference of argument 3
[ 1.489261] print_fmt: "%s, netdev:%s(%d), bssid: %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->bssid)
[ 1.490810] event rdev_set_pmksa has unsafe dereference of argument 3
[ 1.491801] print_fmt: "%s, netdev:%s(%d), bssid: %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->bssid)
[ 1.493370] event rdev_probe_client has unsafe dereference of argument 3
[ 1.494406] print_fmt: "%s, netdev:%s(%d), %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer)
[ 1.495844] event rdev_tdls_oper has unsafe dereference of argument 3
[ 1.496849] print_fmt: "%s, netdev:%s(%d), %pM, oper: %d", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer), REC->oper
[ 1.498575] event rdev_tdls_mgmt has unsafe dereference of argument 3
[ 1.499569] print_fmt: "%s, netdev:%s(%d), %pM, action_code: %u, dialog_token: %u, status_code: %u, peer_capability: %u initiator: %s buf: %#.2x ", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer), REC->action_code, REC->dialog_token, REC->status_code, REC->peer_capability, (REC->initiator) ? "true" : "false", ((u8 *)__get_dynamic_array(buf))[0]
[ 1.504375] event rdev_set_bitrate_mask has unsafe dereference of argument 3
[ 1.505466] print_fmt: "%s, netdev:%s(%d), peer: %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->peer)
[ 1.506995] event rdev_join_ibss has unsafe dereference of argument 3
[ 1.508000] print_fmt: "%s, netdev:%s(%d), bssid: %pM, ssid: %s", REC->wiphy_name, REC->name, REC->ifindex, (REC->bssid), REC->ssid
[ 1.509842] event rdev_connect has unsafe dereference of argument 3
[ 1.510807] print_fmt: "%s, netdev:%s(%d), bssid: %pM, ssid: %s, auth type: %d, privacy: %s, wpa versions: %u, flags: %u, previous bssid: %pM", REC->wiphy_name, REC->name, REC->ifindex, (REC->bssid), REC->ssid, REC->auth_type, (REC->privacy) ? "true" : "false", REC->wpa_versions, REC->flags, (REC->prev_bssid)
[ 1.515044] event rdev_disassoc has unsafe dereference of argument 3
[ 1.516041] print_fmt: "%s, netdev:%s(%d), bssid: %pM, reason: %u, local state change: %s", REC->wiphy_name, REC->name, REC->ifindex, (REC->bssid), REC->reason_code, (REC->local_state_change) ? "true" : "false"
[ 1.518933] event rdev_deauth has unsafe dereference of argument 3
[ 1.519885] print_fmt: "%s, netdev:%s(%d), bssid: %pM, reason: %u", REC->wiphy_name, REC->name, REC->ifindex, (REC->bssid), REC->reason_code
[ 1.521840] event rdev_assoc has unsafe dereference of argument 3
[ 1.522783] print_fmt: "%s, netdev:%s(%d), bssid: %pM, previous bssid: %pM, use mfp: %s, flags: %u", REC->wiphy_name, REC->name, REC->ifindex, (REC->bssid), (REC->prev_bssid), (REC->use_mfp) ? "true" : "false", REC->flags
[ 1.525817] event rdev_auth has unsafe dereference of argument 4
[ 1.526742] print_fmt: "%s, netdev:%s(%d), auth type: %d, bssid: %pM", REC->wiphy_name, REC->name, REC->ifindex, REC->auth_type, (REC->bssid)
[ 1.528736] event rdev_dump_mpp has unsafe dereference of argument 4
[ 1.529718] print_fmt: "%s, netdev:%s(%d), index: %d, destination: %pM, mpp: %pM", REC->wiphy_name, REC->name, REC->ifindex, REC->idx, (REC->dst), (REC->mpp)
[ 1.531895] event rdev_get_mpp has unsafe dereference of argument 3
To reproduce:
# build kernel
cd linux
cp config-5.11.0-11483-g5c71984c2178 .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
Thanks,
Oliver Sang
View attachment "config-5.11.0-11483-g5c71984c2178" of type "text/plain" (140699 bytes)
View attachment "job-script" of type "text/plain" (4620 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (16848 bytes)
Powered by blists - more mailing lists