From: Hao, Shun <shun.hao@intel.com>
To: lkp@lists.01.org
Subject: Re: [lkp-robot] [printk] c162d5b433: BUG:KASAN:use-after-scope_in_c
Date: Fri, 02 Mar 2018 03:48:40 +0000 [thread overview]
Message-ID: <1519962555.10510.1.camel@intel.com> (raw)
In-Reply-To: <CACT4Y+ZuCq+yN3YwusmHuv1CN86CfEYEhaJGoaD7xLG9irgyYw@mail.gmail.com>
[-- Attachment #1: Type: text/plain, Size: 5667 bytes --]
sorry for missing the attached script in original mail, here to add it.
On Thu, 2018-03-01 at 08:47 +0000, Dmitry Vyukov wrote:
> On Thu, Mar 1, 2018 at 2:37 AM, Sergey Senozhatsky
> <sergey.senozhatsky@gmail.com> wrote:
> > Hello,
> >
> > Cc-ing Dmitry Vyukov and kasan-dev on this.
> >
> > On (02/28/18 16:59), Petr Mladek wrote:
> > [..]
> > > > >
> > > > > [ 0.003333] BUG: KASAN: use-after-scope in
> > > > > console_unlock+0x185/0x960
> > > > > [ 0.003333] BUG: KASAN: use-after-scope in
> > > > > console_unlock+0x185/0x960
> > > >
> > > > Is there any change to get disassembly of console_unlock() from
> > > > the
> > > > problematic build?
> > > >
> > > > I have troubles to reproduce this myself. Also I was not able
> > > > to find any
> > > > bug just by looking into the code yet. The disassembly might
> > > > help
> > > > a lot here.
> > > >
> > > >
> > > > Interesting symptoms (for myself and other debuggers):
> > > >
> > > > The lines are duplicated. Therefore it happened when real
> > > > console was registered and before the early console was
> > > > unregistered.
> > > > See also the full dmesg for these actions. The related printk
> > > > messages
> > > > are right after the KASAN report.
> > > >
> > > > I wonder if it is unsafe to pass the console_lock via
> > > > console_trylock_spinnning() from console_unlock() called
> > > > in register_console(). I do not see any problem but I might
> > > > be blind.
> >
> > I'm not sure it we actually have concurrent printks at that state
> > yet,
> > might be too early for any printk offloading. The backtrace still
> > makes no sense to me at all, tho. We had this report twice,
> > probably,
> > already (even before the offloading patchset, if I'm not mistaken).
> >
> > https://marc.info/?l=linux-kernel&m=151200883525299
> >
> > [..]
> > > I feel lost a bit.
> >
> > Yeah... can't understand what's going on there.
> >
> > The last time kasan didn't like this part
> >
> > [ 0.003333] ? console_unlock+0x605/0xcc0:
> > atomic_read at
> > arch/x86/include/asm/atomic.h:27
> > (inlined by) static_key_count at
> > include/linux/jump_label.h:191
> > (inlined by) static_key_false at
> > include/linux/jump_label.h:201
> > (inlined by) trace_console_rcuidle
> > at include/trace/events/printk.h:10
> > (inlined by) call_console_drivers at
> > kernel/printk/printk.c:1556
> > (inlined by) console_unlock at
> > kernel/printk/printk.c:2233
> >
> > complaining that there was a write of size 4... at atomic_read().
> >
> > Now it's reporting that the write of size 1 was out of scope.
> >
> > > I am really curious what code is proceed on the line
> > > console_unlock+0x185/0x960.
> >
> > Agreed.
> >
> > On my system 0x185/0x960 is somewhere around
> >
> >
> > 191e: 89 d7 mov %edx,%edi
> > 1920: e8 06 e7 ff ff callq 2b <log_next>
> > 1925: 48 89 2d 00 00 00
> > 00 mov %rbp,0x0(%rip) # 192c <console_unlock+0x17f>
> > 192c: 89 05 00 00 00
> > 00 mov %eax,0x0(%rip) # 1932 <console_unlock+0x185>
> > > > 1932: eb a9 jmp 18dd
> > > > <console_unlock+0x130>
> >
> > 1934: 8b 35 00 00 00
> > 00 mov 0x0(%rip),%esi # 193a <console_unlock+0x18d>
> > 193a: b9 00 04 00 00 mov $0x400,%ecx
> > 193f: 4c 89 ef mov %r13,%rdi
> > 1942: 31 ed xor %ebp,%ebp
> >
> >
> > That jmp 18dd after log_next() is a `goto skip' in
> > suppress_message_printing() branch
> >
> > skip:
> > if (console_seq == log_next_seq)
> > break;
> >
> > msg = log_from_idx(console_idx);
> > if (suppress_message_printing(msg->level)) {
> > /*
> > * Skip record we have buffered and already
> > printed
> > * directly to the console when we received
> > it, and
> > * record that has level above the console
> > loglevel.
> > */
> > console_idx = log_next(console_idx);
> > console_seq++;
> > > > goto skip;
> >
> > }
> >
> >
> > As far as I can tell.
>
>
> Hi Shun,
>
> The report says "job-script is attached in this email", but I don't
> see it attached. Did you forget to attach it? How can I reproduce
> this
> exact build?
> Could you post a symbolized report with inlines frames?
[-- Attachment #2: job-script.bin --]
[-- Type: application/x-shellscript, Size: 4415 bytes --]
WARNING: multiple messages have this Message-ID (diff)
From: "Hao, Shun" <shun.hao@intel.com>
To: "dvyukov@google.com" <dvyukov@google.com>,
"sergey.senozhatsky@gmail.com" <sergey.senozhatsky@gmail.com>
Cc: "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>,
"peterz@infradead.org" <peterz@infradead.org>,
"rostedt@goodmis.org" <rostedt@goodmis.org>,
"torvalds@linux-foundation.org" <torvalds@linux-foundation.org>,
"penguin-kernel@i-love.sakura.ne.jp"
<penguin-kernel@i-love.sakura.ne.jp>,
"vbabka@suse.cz" <vbabka@suse.cz>,
"xiyou.wangcong@gmail.com" <xiyou.wangcong@gmail.com>,
"pavel@ucw.cz" <pavel@ucw.cz>,
"hannes@cmpxchg.org" <hannes@cmpxchg.org>,
"kasan-dev@googlegroups.com" <kasan-dev@googlegroups.com>,
"pmladek@suse.com" <pmladek@suse.com>,
"mhocko@kernel.org" <mhocko@kernel.org>,
"byungchul.park@lge.com" <byungchul.park@lge.com>,
"Hansen, Dave" <dave.hansen@intel.com>,
"tj@kernel.org" <tj@kernel.org>,
"mgorman@suse.de" <mgorman@suse.de>, "lkp@01.org" <lkp@01.org>,
"mathieu.desnoyers@efficios.com" <mathieu.desnoyers@efficios.com>,
"jack@suse.cz" <jack@suse.cz>
Subject: Re: [lkp-robot] [printk] c162d5b433: BUG:KASAN:use-after-scope_in_c
Date: Fri, 2 Mar 2018 03:48:40 +0000 [thread overview]
Message-ID: <1519962555.10510.1.camel@intel.com> (raw)
In-Reply-To: <CACT4Y+ZuCq+yN3YwusmHuv1CN86CfEYEhaJGoaD7xLG9irgyYw@mail.gmail.com>
[-- Attachment #1: Type: text/plain, Size: 5665 bytes --]
sorry for missing the attached script in original mail, here to add it.
On Thu, 2018-03-01 at 08:47 +0000, Dmitry Vyukov wrote:
> On Thu, Mar 1, 2018 at 2:37 AM, Sergey Senozhatsky
> <sergey.senozhatsky@gmail.com> wrote:
> > Hello,
> >
> > Cc-ing Dmitry Vyukov and kasan-dev on this.
> >
> > On (02/28/18 16:59), Petr Mladek wrote:
> > [..]
> > > > >
> > > > > [ 0.003333] BUG: KASAN: use-after-scope in
> > > > > console_unlock+0x185/0x960
> > > > > [ 0.003333] BUG: KASAN: use-after-scope in
> > > > > console_unlock+0x185/0x960
> > > >
> > > > Is there any change to get disassembly of console_unlock() from
> > > > the
> > > > problematic build?
> > > >
> > > > I have troubles to reproduce this myself. Also I was not able
> > > > to find any
> > > > bug just by looking into the code yet. The disassembly might
> > > > help
> > > > a lot here.
> > > >
> > > >
> > > > Interesting symptoms (for myself and other debuggers):
> > > >
> > > > The lines are duplicated. Therefore it happened when real
> > > > console was registered and before the early console was
> > > > unregistered.
> > > > See also the full dmesg for these actions. The related printk
> > > > messages
> > > > are right after the KASAN report.
> > > >
> > > > I wonder if it is unsafe to pass the console_lock via
> > > > console_trylock_spinnning() from console_unlock() called
> > > > in register_console(). I do not see any problem but I might
> > > > be blind.
> >
> > I'm not sure it we actually have concurrent printks at that state
> > yet,
> > might be too early for any printk offloading. The backtrace still
> > makes no sense to me at all, tho. We had this report twice,
> > probably,
> > already (even before the offloading patchset, if I'm not mistaken).
> >
> > https://marc.info/?l=linux-kernel&m=151200883525299
> >
> > [..]
> > > I feel lost a bit.
> >
> > Yeah... can't understand what's going on there.
> >
> > The last time kasan didn't like this part
> >
> > [ 0.003333] ? console_unlock+0x605/0xcc0:
> > atomic_read at
> > arch/x86/include/asm/atomic.h:27
> > (inlined by) static_key_count at
> > include/linux/jump_label.h:191
> > (inlined by) static_key_false at
> > include/linux/jump_label.h:201
> > (inlined by) trace_console_rcuidle
> > at include/trace/events/printk.h:10
> > (inlined by) call_console_drivers at
> > kernel/printk/printk.c:1556
> > (inlined by) console_unlock at
> > kernel/printk/printk.c:2233
> >
> > complaining that there was a write of size 4... at atomic_read().
> >
> > Now it's reporting that the write of size 1 was out of scope.
> >
> > > I am really curious what code is proceed on the line
> > > console_unlock+0x185/0x960.
> >
> > Agreed.
> >
> > On my system 0x185/0x960 is somewhere around
> >
> >
> > 191e: 89 d7 mov %edx,%edi
> > 1920: e8 06 e7 ff ff callq 2b <log_next>
> > 1925: 48 89 2d 00 00 00
> > 00 mov %rbp,0x0(%rip) # 192c <console_unlock+0x17f>
> > 192c: 89 05 00 00 00
> > 00 mov %eax,0x0(%rip) # 1932 <console_unlock+0x185>
> > > > 1932: eb a9 jmp 18dd
> > > > <console_unlock+0x130>
> >
> > 1934: 8b 35 00 00 00
> > 00 mov 0x0(%rip),%esi # 193a <console_unlock+0x18d>
> > 193a: b9 00 04 00 00 mov $0x400,%ecx
> > 193f: 4c 89 ef mov %r13,%rdi
> > 1942: 31 ed xor %ebp,%ebp
> >
> >
> > That jmp 18dd after log_next() is a `goto skip' in
> > suppress_message_printing() branch
> >
> > skip:
> > if (console_seq == log_next_seq)
> > break;
> >
> > msg = log_from_idx(console_idx);
> > if (suppress_message_printing(msg->level)) {
> > /*
> > * Skip record we have buffered and already
> > printed
> > * directly to the console when we received
> > it, and
> > * record that has level above the console
> > loglevel.
> > */
> > console_idx = log_next(console_idx);
> > console_seq++;
> > > > goto skip;
> >
> > }
> >
> >
> > As far as I can tell.
>
>
> Hi Shun,
>
> The report says "job-script is attached in this email", but I don't
> see it attached. Did you forget to attach it? How can I reproduce
> this
> exact build?
> Could you post a symbolized report with inlines frames?
[-- Attachment #2: job-script --]
[-- Type: application/x-shellscript, Size: 4415 bytes --]
next prev parent reply other threads:[~2018-03-02 3:48 UTC|newest]
Thread overview: 29+ messages / expand[flat|nested] mbox.gz Atom feed top
2018-02-24 5:34 [lkp-robot] [printk] c162d5b433: BUG:KASAN:use-after-scope_in_c kernel test robot
2018-02-24 5:34 ` kernel test robot
2018-02-28 10:23 ` Petr Mladek
2018-02-28 10:23 ` Petr Mladek
2018-02-28 15:59 ` Petr Mladek
2018-02-28 15:59 ` Petr Mladek
2018-03-01 1:08 ` Tetsuo Handa
2018-03-01 1:37 ` Sergey Senozhatsky
2018-03-01 1:37 ` Sergey Senozhatsky
2018-03-01 8:47 ` Dmitry Vyukov
2018-03-01 8:47 ` Dmitry Vyukov
2018-03-01 10:06 ` Tetsuo Handa
2018-03-01 14:09 ` Dmitry Vyukov
2018-03-01 14:09 ` Dmitry Vyukov
2018-03-01 14:14 ` Ard Biesheuvel
2018-03-01 14:14 ` Ard Biesheuvel
2018-03-01 16:38 ` Kees Cook
2018-03-01 16:38 ` Kees Cook
2018-03-02 3:48 ` Hao, Shun [this message]
2018-03-02 3:48 ` Hao, Shun
2018-03-01 8:51 ` Dmitry Vyukov
2018-03-01 8:51 ` Dmitry Vyukov
2018-03-01 15:19 ` Sergey Senozhatsky
2018-03-01 15:19 ` Sergey Senozhatsky
2018-03-01 15:53 ` Dmitry Vyukov
2018-03-01 15:53 ` Dmitry Vyukov
2018-03-02 5:10 ` Sergey Senozhatsky
2018-03-02 5:10 ` Sergey Senozhatsky
2018-03-01 3:26 ` Tetsuo Handa
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=1519962555.10510.1.camel@intel.com \
--to=shun.hao@intel.com \
--cc=lkp@lists.01.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.