lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
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