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 [ 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 job-script # job-script is attached in this email Thanks, Oliver Sang