From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753287AbbDQHo6 (ORCPT ); Fri, 17 Apr 2015 03:44:58 -0400 Received: from mailout1.w1.samsung.com ([210.118.77.11]:65378 "EHLO mailout1.w1.samsung.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750951AbbDQHov (ORCPT ); Fri, 17 Apr 2015 03:44:51 -0400 X-AuditID: cbfec7f5-f794b6d000001495-07-5530b9f2dce0 Message-id: <5530B9EA.9070203@samsung.com> Date: Fri, 17 Apr 2015 10:44:42 +0300 From: Andrey Ryabinin User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.5.0 MIME-version: 1.0 To: Sasha Levin , Steven Rostedt Cc: linux-kernel@vger.kernel.org, Ingo Molnar , Andrew Morton , Arnaldo Carvalho de Melo , Namhyung Kim , Masami Hiramatsu , Mathieu Desnoyers , Guilherme Cox , Tony Luck , Xie XiuQi Subject: Re: [PATCH 07/18 v3] tracing: Add TRACE_DEFINE_ENUM() macro to map enums to their values References: <20150403013802.220157513@goodmis.org> <20150403014123.997385206@goodmis.org> <552E661D.5060502@oracle.com> <20150415100549.09cabb59@gandalf.local.home> <552F0937.4010009@oracle.com> <20150416232116.39cd9f74@grimm.local.home> <5530852A.70202@oracle.com> In-reply-to: <5530852A.70202@oracle.com> Content-type: text/plain; charset=windows-1252 Content-transfer-encoding: 7bit X-Brightmail-Tracker: H4sIAAAAAAAAA+NgFuphkeLIzCtJLcpLzFFi42I5/e/4Zd3POw1CDXbMY7ToureDzWLO+jVs FlMnLGWyuLxrDpvF+r1rmCw2nz3DbLH63ylGi6ZlW1ks9nU8YLJYfOQ2s8WJK3uYLT4v/8Pm wOPRsqqX2WPp6TdsHjtn3WX3aNl3i92j9cwaFo+WI29ZPTat6mTzODHjN4vHx6e3WDw+b5IL 4IrisklJzcksSy3St0vgyti3dT5bwST1ikvNv1gaGH/LdzFyckgImEi8vnGLFcIWk7hwbz1b FyMXh5DAUkaJmw/nsUA43xkljhy/CeRwcPAKaEkc+WoA0sAioCpxe/ciRhCbTUBP4t+s7Wwg JaICERK3L3OChHkFBCV+TL7HAmKLCPhJXP34iBlkJLPAVGaJAxv+sIEkhAWSJdoOzGWF2NXP JNF98hBYB6eAhsSPs1OYQYYyAy24f1ELJMwsIC+xec1b5gmMArOQ7JiFUDULSdUCRuZVjKKp pckFxUnpuUZ6xYm5xaV56XrJ+bmbGCFx9HUH49JjVocYBTgYlXh4NwQahAqxJpYVV+YeYpTg YFYS4eXYBhTiTUmsrEotyo8vKs1JLT7EKM3BoiTOO3PX+xAhgfTEktTs1NSC1CKYLBMHp1QD 43Lubz8YD70w+RTsHFCks9D8uNDZXX1htWar7O8VVuzj0D8pwyh7qutj4ezgPNWdIR+PhbGp VEyMbv3XNCHric4G1gmNr3h4xJXmbg9m3H/iv/gJPlW20mlbmL3OKS6Nil16jskx4eOyu5XB XmHabwy5TBs3znq6/a2XKt/n2XI8P/wlF4QIKbEUZyQaajEXFScCAFSGk6efAgAA Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 04/17/2015 06:59 AM, Sasha Levin wrote: > On 04/16/2015 11:21 PM, Steven Rostedt wrote: >> On Wed, 15 Apr 2015 20:58:31 -0400 >> Sasha Levin wrote: >> >>>> On 04/15/2015 10:05 AM, Steven Rostedt wrote: >>>>>> On Wed, 15 Apr 2015 09:22:37 -0400 >>>>>> Sasha Levin wrote: >>>>>> >>>>>>>> Hey Steven, >>>>>>>> >>>>>>>> I'm seeing the following when booting: >>>>>>>> >>>>>>>> [ 10.678876] BUG: KASan: out of bounds access in trace_event_enum_update+0xb1d/0xb70 at addr ffffffffa6c4dc68 >>>>>> >>>>>> Thanks for the report. Mind sending me over your config, and which git >>>>>> commit was your HEAD. I can't seem to find 7858a62 from your output. >>>> >>>> It reproduces on the latest -next kernel. I've attached my config. >>>> >> What version of gcc is required to run KASan, the highest version I >> have to build kernels with is 4.9.0 >> >> I have no idea what event caused the issue :-/ > > 4.9.2+ is needed for KASan. > Actually, detection of out of bounds accesses to stack and global variables works only with gcc 5+ And this is out-of-bounds access to global variable print_fmt_9p_client_req. Line numbers in report is ambiguous, so I did following change to reduce compiler's optimization and get more clear line numbers. diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c index 7da1dfe..40c31b6 100644 --- a/kernel/trace/trace_events.c +++ b/kernel/trace/trace_events.c @@ -1726,7 +1726,7 @@ static char *enum_replace(char *ptr, struct trace_enum_map *map, int len) return ptr + elen; } -static void update_event_printk(struct ftrace_event_call *call, +__attribute__((optimize("O0"))) static noinline void update_event_printk(struct ftrace_event_call *call, struct trace_enum_map *map) { char *ptr This ended up in this splat (which has more sane line numbers): [ 0.123688] ================================================================== [ 0.123688] BUG: KASan: out of bounds access in update_event_printk+0x6fe/0x720 at addr ffffffff821654a8 [ 0.123688] Read of size 1 by task swapper/0/1 [ 0.123688] Address belongs to variable print_fmt_9p_client_req+0x848/0x880 [ 0.124000] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 4.0.0+ #269 [ 0.124000] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.7.5.1-0-g8936dbb-20141113_115728-nilsson.home.kraxel.org 04/01/2014 [ 0.124000] ffffffff82165720 ffff8801f4d17be8 ffffffff81cc0d35 000000000000003f [ 0.124000] ffff8801f4d17c80 ffff8801f4d17c68 ffffffff8139cafc ffff8801f4d17c28 [ 0.124000] ffffffff8139c39d 0000000000000292 ffffffff81397c5c ffff8801f4d17c38 [ 0.124000] Call Trace: [ 0.124000] dump_stack (lib/dump_stack.c:52) [ 0.124000] kasan_report_error (mm/kasan/report.c:132 mm/kasan/report.c:193) [ 0.124000] ? kasan_slab_alloc (mm/kasan/kasan.c:325) [ 0.124000] ? kmem_cache_alloc (mm/slub.c:2522) [ 0.124000] __asan_report_load1_noabort (mm/kasan/report.c:248) [ 0.124000] ? update_event_printk (kernel/trace/trace_events.c:1736 (discriminator 1)) [ 0.124000] update_event_printk (kernel/trace/trace_events.c:1736 (discriminator 1)) [ 0.124000] trace_event_enum_update (kernel/trace/trace_events.c:1819) [ 0.124000] ? tracefs_create_file (fs/tracefs/inode.c:413) [ 0.124000] tracer_init_tracefs (kernel/trace/trace.c:4122 kernel/trace/trace.c:6750 kernel/trace/trace.c:6848) [ 0.124000] ? set_tracepoint_printk (kernel/trace/trace.c:6825) [ 0.124000] do_one_initcall (init/main.c:788) [ 0.124000] ? try_to_run_init_process (init/main.c:777) [ 0.124000] ? parse_args (kernel/params.c:218) [ 0.124000] kernel_init_freeable (init/main.c:853 init/main.c:861 init/main.c:880 init/main.c:1001) [ 0.124000] ? __switch_to (arch/x86/include/asm/paravirt.h:25 arch/x86/kernel/process_64.c:410) [ 0.124000] ? rest_init (init/main.c:928) [ 0.124000] kernel_init (init/main.c:933) [ 0.124000] ? rest_init (init/main.c:928) [ 0.124000] ret_from_fork (arch/x86/kernel/entry_64.S:631) [ 0.124000] ? rest_init (init/main.c:928) [ 0.124000] Memory state around the buggy address: [ 0.124000] ffffffff82165380: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 [ 0.124000] ffffffff82165400: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 [ 0.124000] >ffffffff82165480: 00 00 00 00 00 fa fa fa fa fa fa fa 00 00 00 00 [ 0.124000] ^ [ 0.124000] ffffffff82165500: fa fa fa fa 00 00 00 00 fa fa fa fa 00 00 00 00 [ 0.124000] ffffffff82165580: fa fa fa fa 00 00 00 00 00 00 00 00 00 00 00 00 [ 0.124000] ================================================================== And kasan is not needed to debug this further. Just stick WARN_ON(ptr > call->print_fmt + strlen(call->print_fmt)) into the 'for' loop in update_event_printk(). > > Thanks, > Sasha >