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]
Message-ID: <7954157A-E523-4041-825B-828A3A38E51B@fb.com>
Date:   Tue, 29 May 2018 16:54:59 +0000
From:   Song Liu <songliubraving@...com>
To:     Thomas Gleixner <tglx@...utronix.de>
CC:     Song Liu <liu.song.a23@...il.com>,
        Tariq Toukan <tariqt@...lanox.com>,
        Dmitry Safonov <0x7f454c46@...il.com>,
        open list <linux-kernel@...r.kernel.org>,
        Maor Gottlieb <maorg@...lanox.com>,
        "Kernel Team" <Kernel-team@...com>
Subject: Re: WARNING and PANIC in irq_matrix_free



> On May 29, 2018, at 1:35 AM, Thomas Gleixner <tglx@...utronix.de> wrote:
> 
> On Mon, 28 May 2018, Song Liu wrote:
>>> On May 28, 2018, at 1:09 PM, Thomas Gleixner <tglx@...utronix.de> wrote:
>>> 
>>> On Mon, 28 May 2018, Song Liu wrote:
>>>> This doesn't fix the issue with bnxt. Here is a trace with this patch:
>>> 
>>> That's just the backtrace which is not really helpful. The real question is
>>> what leads to this scenaria.
>>> 
>>> What I was asking for is to enable the irq_vector and irq_matrix trace
>>> points along with ftrace_dump_on_oops. The latter dumps the trace buffer
>>> when the problem happens and that should give us a hint what actually
>>> causes that.
>> 
>> Attached is the dump I got. It seems pretty noisy, with many message lost.
>> 
>> Maybe we cannot enable all trace points under irq_vectors/ and irq_matrix.
> 
> Right. Sorry, I forgot to say that we only need the irq_vectors ones which
> are related to vector allocation, i.e.: irq_vectors/vector_* 
> 
> Thanks,
> 
> 	tglx

Here is the ftrace dump:

[ 1609.472697]    <...>-53363  19d... 1610359225us : vector_deactivate: irq=29 is_managed=0 can_reserve=1 reserve=0
[ 1609.472698]    <...>-53363  19d... 1610359229us : vector_clear: irq=29 vector=33 cpu=21 prev_vector=0 prev_cpu=0
[ 1609.472699]    <...>-53363  19d... 1610359230us : irq_matrix_free: bit=33 cpu=21 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11239, global_rsvd=23, total_alloc=17
[ 1609.472699]    <...>-53363  19d... 1610359231us : irq_matrix_reserve: online_maps=56 global_avl=11239, global_rsvd=24, total_alloc=17
[ 1609.472700]    <...>-53363  19d... 1610359232us : vector_reserve: irq=29 ret=0
[ 1609.472700]    <...>-53363  19d... 1610359233us : vector_config: irq=29 vector=239 cpu=0 apicdest=0x00000000
[ 1609.472701]    <...>-53363  19d... 1610359242us : vector_deactivate: irq=30 is_managed=0 can_reserve=1 reserve=0
[ 1609.472701]    <...>-53363  19d... 1610359242us : vector_clear: irq=30 vector=33 cpu=11 prev_vector=0 prev_cpu=1
[ 1609.472701]    <...>-53363  19d... 1610359242us : irq_matrix_free: bit=33 cpu=11 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11240, global_rsvd=24, total_alloc=16
[ 1609.472702]    <...>-53363  19d... 1610359243us : irq_matrix_reserve: online_maps=56 global_avl=11240, global_rsvd=25, total_alloc=16
[ 1609.472702]    <...>-53363  19d... 1610359243us : vector_reserve: irq=30 ret=0
[ 1609.472703]    <...>-53363  19d... 1610359243us : vector_config: irq=30 vector=239 cpu=0 apicdest=0x00000000
[ 1609.472703]    <...>-53363  19d... 1610359248us : vector_deactivate: irq=31 is_managed=0 can_reserve=1 reserve=0
[ 1609.472703]    <...>-53363  19d... 1610359248us : vector_clear: irq=31 vector=33 cpu=20 prev_vector=0 prev_cpu=2
[ 1609.472704]    <...>-53363  19d... 1610359249us : irq_matrix_free: bit=33 cpu=20 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11241, global_rsvd=25, total_alloc=15
[ 1609.472704]    <...>-53363  19d... 1610359249us : irq_matrix_reserve: online_maps=56 global_avl=11241, global_rsvd=26, total_alloc=15
[ 1609.472705]    <...>-53363  19d... 1610359249us : vector_reserve: irq=31 ret=0
[ 1609.472705]    <...>-53363  19d... 1610359249us : vector_config: irq=31 vector=239 cpu=0 apicdest=0x00000000
[ 1609.472705]    <...>-53363  19d... 1610359255us : vector_deactivate: irq=32 is_managed=0 can_reserve=1 reserve=0
[ 1609.472706]    <...>-53363  19d... 1610359255us : vector_clear: irq=32 vector=33 cpu=9 prev_vector=0 prev_cpu=3
[ 1609.472707]    <...>-53363  19d... 1610359255us : irq_matrix_free: bit=33 cpu=9 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11242, global_rsvd=26, total_alloc=14
[ 1609.472707]    <...>-53363  19d... 1610359256us : irq_matrix_reserve: online_maps=56 global_avl=11242, global_rsvd=27, total_alloc=14
[ 1609.472708]    <...>-53363  19d... 1610359256us : vector_reserve: irq=32 ret=0
[ 1609.472708]    <...>-53363  19d... 1610359256us : vector_config: irq=32 vector=239 cpu=0 apicdest=0x00000000
[ 1609.472709]    <...>-53363  19d... 1610359261us : vector_deactivate: irq=33 is_managed=0 can_reserve=1 reserve=0
[ 1609.472709]    <...>-53363  19d... 1610359261us : vector_clear: irq=33 vector=33 cpu=18 prev_vector=0 prev_cpu=4
[ 1609.472710]    <...>-53363  19d... 1610359262us : irq_matrix_free: bit=33 cpu=18 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11243, global_rsvd=27, total_alloc=13
[ 1609.472710]    <...>-53363  19d... 1610359262us : irq_matrix_reserve: online_maps=56 global_avl=11243, global_rsvd=28, total_alloc=13
[ 1609.472711]    <...>-53363  19d... 1610359262us : vector_reserve: irq=33 ret=0
[ 1609.472711]    <...>-53363  19d... 1610359262us : vector_config: irq=33 vector=239 cpu=0 apicdest=0x00000000
[ 1609.472711]    <...>-53363  19d... 1610359268us : vector_deactivate: irq=34 is_managed=0 can_reserve=1 reserve=0
[ 1609.472712]    <...>-53363  19d... 1610359268us : vector_clear: irq=34 vector=34 cpu=7 prev_vector=0 prev_cpu=5
[ 1609.472712]    <...>-53363  19d... 1610359268us : irq_matrix_free: bit=34 cpu=7 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11244, global_rsvd=28, total_alloc=12
[ 1609.472713]    <...>-53363  19d... 1610359268us : irq_matrix_reserve: online_maps=56 global_avl=11244, global_rsvd=29, total_alloc=12
[ 1609.472713]    <...>-53363  19d... 1610359269us : vector_reserve: irq=34 ret=0
[ 1609.472713]    <...>-53363  19d... 1610359269us : vector_config: irq=34 vector=239 cpu=0 apicdest=0x00000000
[ 1609.472714]    <...>-53363  19d... 1610359279us : vector_deactivate: irq=35 is_managed=0 can_reserve=1 reserve=0
[ 1609.472714]    <...>-53363  19d... 1610359279us : vector_clear: irq=35 vector=33 cpu=26 prev_vector=0 prev_cpu=6
[ 1609.472715]    <...>-53363  19d... 1610359279us : irq_matrix_free: bit=33 cpu=26 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11245, global_rsvd=29, total_alloc=11
[ 1609.472715]    <...>-53363  19d... 1610359279us : irq_matrix_reserve: online_maps=56 global_avl=11245, global_rsvd=30, total_alloc=11
[ 1609.472715]    <...>-53363  19d... 1610359280us : vector_reserve: irq=35 ret=0
[ 1609.472716]    <...>-53363  19d... 1610359280us : vector_config: irq=35 vector=239 cpu=0 apicdest=0x00000000
[ 1609.472716]    <...>-53363  19d... 1610359285us : vector_deactivate: irq=36 is_managed=0 can_reserve=1 reserve=0
[ 1609.472717]    <...>-53363  19d... 1610359285us : vector_clear: irq=36 vector=33 cpu=10 prev_vector=0 prev_cpu=7
[ 1609.472717]    <...>-53363  19d... 1610359286us : irq_matrix_free: bit=33 cpu=10 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11246, global_rsvd=30, total_alloc=10
[ 1609.472718]    <...>-53363  19d... 1610359286us : irq_matrix_reserve: online_maps=56 global_avl=11246, global_rsvd=31, total_alloc=10
[ 1609.472718]    <...>-53363  19d... 1610359286us : vector_reserve: irq=36 ret=0
[ 1609.472718]    <...>-53363  19d... 1610359286us : vector_config: irq=36 vector=239 cpu=0 apicdest=0x00000000
[ 1609.472719]    <...>-53363  20d... 1610366617us : vector_activate: irq=29 is_managed=0 can_reserve=1 reserve=0
[ 1609.472719]    <...>-53363  20d... 1610366619us : vector_alloc: irq=29 vector=4294967268 reserved=1 ret=0
[ 1609.472719]    <...>-53363  20d... 1610366621us : irq_matrix_alloc: bit=33 cpu=7 online=1 avl=200 alloc=1 managed=0 online_maps=56 global_avl=11245, global_rsvd=30, total_alloc=11
[ 1609.472720]    <...>-53363  20d... 1610366623us : vector_update: irq=29 vector=33 cpu=7 prev_vector=0 prev_cpu=21
[ 1609.472720]    <...>-53363  20d... 1610366623us : vector_alloc: irq=29 vector=33 reserved=1 ret=0
[ 1609.472721]    <...>-53363  20d... 1610366623us : vector_config: irq=29 vector=33 cpu=7 apicdest=0x00000010
[ 1609.472721]    <...>-53363  20d... 1610366629us : irq_matrix_alloc: bit=33 cpu=21 online=1 avl=200 alloc=1 managed=0 online_maps=56 global_avl=11244, global_rsvd=30, total_alloc=12
[ 1609.472722]    <...>-53363  20d... 1610366629us : vector_update: irq=29 vector=33 cpu=21 prev_vector=33 prev_cpu=7
[ 1609.472723]    <...>-53363  20d... 1610366629us : vector_alloc: irq=29 vector=33 reserved=1 ret=0
[ 1609.472723]    <...>-53363  20d... 1610366630us : vector_config: irq=29 vector=33 cpu=21 apicdest=0x00000030
[ 1609.472724]    <...>-53363  20d... 1610366637us : irq_matrix_alloc: bit=35 cpu=0 online=1 avl=197 alloc=4 managed=0 online_maps=56 global_avl=11243, global_rsvd=30, total_alloc=13
[ 1609.472724]    <...>-53363  20d... 1610366637us : vector_update: irq=29 vector=35 cpu=0 prev_vector=33 prev_cpu=21
[ 1609.472725]    <...>-53363  20d... 1610366637us : vector_alloc: irq=29 vector=35 reserved=1 ret=0
[ 1609.472725]    <...>-53363  20d... 1610366638us : vector_config: irq=29 vector=35 cpu=0 apicdest=0x00000000
[ 1609.472725]    <...>-53363  20dN.. 1610366643us : vector_activate: irq=30 is_managed=0 can_reserve=1 reserve=0
[ 1609.472726]    <...>-53363  20dN.. 1610366644us : irq_matrix_alloc: bit=33 cpu=11 online=1 avl=200 alloc=1 managed=0 online_maps=56 global_avl=11242, global_rsvd=29, total_alloc=14
[ 1609.472726]    <...>-53363  20dN.. 1610366644us : vector_update: irq=30 vector=33 cpu=11 prev_vector=0 prev_cpu=11
[ 1609.472727]    <...>-53363  20dN.. 1610366644us : vector_alloc: irq=30 vector=33 reserved=1 ret=0
[ 1609.472727]    <...>-53363  20dN.. 1610366644us : vector_config: irq=30 vector=33 cpu=11 apicdest=0x00000018
[ 1609.472727]    <...>-53363  20dN.. 1610366647us : vector_config: irq=30 vector=33 cpu=11 apicdest=0x00000018
[ 1609.472728]    <...>-53363  20dN.. 1610366650us : irq_matrix_alloc: bit=34 cpu=1 online=1 avl=199 alloc=2 managed=0 online_maps=56 global_avl=11241, global_rsvd=29, total_alloc=15
[ 1609.472728]    <...>-53363  20dN.. 1610366651us : vector_update: irq=30 vector=34 cpu=1 prev_vector=33 prev_cpu=11
[ 1609.472729]    <...>-53363  20dN.. 1610366651us : vector_alloc: irq=30 vector=34 reserved=1 ret=0
[ 1609.472729]    <...>-53363  20dN.. 1610366651us : vector_config: irq=30 vector=34 cpu=1 apicdest=0x00000002
[ 1609.472729]    <...>-53363  20dN.. 1610366654us : vector_activate: irq=31 is_managed=0 can_reserve=1 reserve=0
[ 1609.472730]    <...>-53363  20dN.. 1610366654us : vector_alloc: irq=31 vector=4294967268 reserved=1 ret=0
[ 1609.472730]    <...>-53363  20dN.. 1610366655us : irq_matrix_alloc: bit=33 cpu=9 online=1 avl=200 alloc=1 managed=0 online_maps=56 global_avl=11240, global_rsvd=28, total_alloc=16
[ 1609.472731]    <...>-53363  20dN.. 1610366655us : vector_update: irq=31 vector=33 cpu=9 prev_vector=0 prev_cpu=20
[ 1609.472731]    <...>-53363  20dN.. 1610366656us : vector_alloc: irq=31 vector=33 reserved=1 ret=0
[ 1609.472731]    <...>-53363  20dN.. 1610366656us : vector_config: irq=31 vector=33 cpu=9 apicdest=0x00000014
[ 1609.472732]   <idle>-0       7d.h. 1610366658us : vector_free_moved: irq=29 cpu=21 vector=33 is_managed=0
[ 1609.472732]   <idle>-0       7d.h. 1610366660us : irq_matrix_free: bit=33 cpu=21 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11241, global_rsvd=28, total_alloc=15
[ 1609.472733]    <...>-53363  20dN.. 1610366662us : irq_matrix_alloc: bit=33 cpu=20 online=1 avl=200 alloc=1 managed=0 online_maps=56 global_avl=11240, global_rsvd=28, total_alloc=16
[ 1609.472733]    <...>-53363  20dN.. 1610366662us : vector_update: irq=31 vector=33 cpu=20 prev_vector=33 prev_cpu=9
[ 1609.472734]    <...>-53363  20dN.. 1610366662us : vector_alloc: irq=31 vector=33 reserved=1 ret=0
[ 1609.472734]    <...>-53363  20dN.. 1610366662us : vector_config: irq=31 vector=33 cpu=20 apicdest=0x0000002c
[ 1609.472735]    <...>-53363  20dN.. 1610366666us : irq_matrix_alloc: bit=34 cpu=2 online=1 avl=199 alloc=2 managed=0 online_maps=56 global_avl=11239, global_rsvd=28, total_alloc=17
[ 1609.472735]    <...>-53363  20dN.. 1610366666us : vector_update: irq=31 vector=34 cpu=2 prev_vector=33 prev_cpu=20
[ 1609.472736]    <...>-53363  20dN.. 1610366666us : vector_alloc: irq=31 vector=34 reserved=1 ret=0
[ 1609.472736]    <...>-53363  20dN.. 1610366666us : vector_config: irq=31 vector=34 cpu=2 apicdest=0x00000004
[ 1609.472737]    <...>-53363  20dNh. 1610366669us : vector_free_moved: irq=31 cpu=20 vector=33 is_managed=0
[ 1609.472737]    <...>-53363  20dNh. 1610366670us : irq_matrix_free: bit=33 cpu=20 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11240, global_rsvd=28, total_alloc=16
[ 1609.472738]    <...>-53363  20dN.. 1610366671us : vector_activate: irq=32 is_managed=0 can_reserve=1 reserve=0
[ 1609.472739]    <...>-53363  20dN.. 1610366671us : irq_matrix_alloc: bit=34 cpu=9 online=1 avl=199 alloc=2 managed=0 online_maps=56 global_avl=11239, global_rsvd=27, total_alloc=17
[ 1609.472739]    <...>-53363  20dN.. 1610366671us : vector_update: irq=32 vector=34 cpu=9 prev_vector=0 prev_cpu=9
[ 1609.472739]    <...>-53363  20dN.. 1610366671us : vector_alloc: irq=32 vector=34 reserved=1 ret=0
[ 1609.472740]    <...>-53363  20dN.. 1610366672us : vector_config: irq=32 vector=34 cpu=9 apicdest=0x00000014
[ 1609.472740]    <...>-53363  20dN.. 1610366674us : vector_config: irq=32 vector=34 cpu=9 apicdest=0x00000014
[ 1609.472741]    <...>-53363  20dN.. 1610366678us : irq_matrix_alloc: bit=34 cpu=3 online=1 avl=199 alloc=2 managed=0 online_maps=56 global_avl=11238, global_rsvd=27, total_alloc=18
[ 1609.472741]    <...>-53363  20dN.. 1610366678us : vector_update: irq=32 vector=34 cpu=3 prev_vector=34 prev_cpu=9
[ 1609.472741]    <...>-53363  20dN.. 1610366679us : vector_alloc: irq=32 vector=34 reserved=1 ret=0
[ 1609.472742]    <...>-53363  20dN.. 1610366679us : vector_config: irq=32 vector=34 cpu=3 apicdest=0x00000006
[ 1609.472742]   <idle>-0      11d.h. 1610366680us : vector_free_moved: irq=30 cpu=11 vector=33 is_managed=0
[ 1609.472743]   <idle>-0      11d.h. 1610366681us : irq_matrix_free: bit=33 cpu=11 online=1 avl=201 alloc=0 managed=0 online_maps=56 global_avl=11239, global_rsvd=27, total_alloc=17
[ 1609.472743]    <...>-53363  20dN.. 1610366683us : vector_activate: irq=33 is_managed=0 can_reserve=1 reserve=0
[ 1609.472743]    <...>-53363  20dN.. 1610366683us : vector_alloc: irq=33 vector=4294967268 reserved=1 ret=0
[ 1609.472744]    <...>-53363  20dN.. 1610366684us : irq_matrix_alloc: bit=33 cpu=10 online=1 avl=200 alloc=1 managed=0 online_maps=56 global_avl=11238, global_rsvd=26, total_alloc=18
[ 1609.472744]    <...>-53363  20dN.. 1610366684us : vector_update: irq=33 vector=33 cpu=10 prev_vector=0 prev_cpu=18
[ 1609.472745]    <...>-53363  20dN.. 1610366684us : vector_alloc: irq=33 vector=33 reserved=1 ret=0
[ 1609.472745]    <...>-53363  20dN.. 1610366685us : vector_config: irq=33 vector=33 cpu=10 apicdest=0x00000016
[ 1609.472745]    <...>-53363  20dN.. 1610366688us : irq_matrix_alloc: bit=33 cpu=18 online=1 avl=200 alloc=1 managed=0 online_maps=56 global_avl=11237, global_rsvd=26, total_alloc=19
[ 1609.472746]    <...>-53363  20dN.. 1610366688us : vector_update: irq=33 vector=33 cpu=18 prev_vector=33 prev_cpu=10
[ 1609.472746]    <...>-53363  20dN.. 1610366688us : vector_alloc: irq=33 vector=33 reserved=1 ret=0
[ 1609.472747]    <...>-53363  20dN.. 1610366688us : vector_config: irq=33 vector=33 cpu=18 apicdest=0x00000028
[ 1609.472747]    <...>-53363  20dN.. 1610366692us : irq_matrix_alloc: bit=34 cpu=4 online=1 avl=199 alloc=2 managed=0 online_maps=56 global_avl=11236, global_rsvd=26, total_alloc=20
[ 1609.472747]    <...>-53363  20dN.. 1610366692us : vector_update: irq=33 vector=34 cpu=4 prev_vector=33 prev_cpu=18
[ 1609.472748]    <...>-53363  20dN.. 1610366692us : vector_alloc: irq=33 vector=34 reserved=1 ret=0
[ 1609.472748]    <...>-53363  20dN.. 1610366693us : vector_config: irq=33 vector=34 cpu=4 apicdest=0x00000008
[ 1609.472749]   <idle>-0       9d.h. 1610366694us : vector_free_moved: irq=32 cpu=9 vector=34 is_managed=0
[ 1609.472749]   <idle>-0       9d.h. 1610366695us : irq_matrix_free: bit=34 cpu=9 online=1 avl=200 alloc=1 managed=0 online_maps=56 global_avl=11237, global_rsvd=26, total_alloc=19
[ 1609.472750]   <idle>-0       9d.h. 1610366696us : vector_free_moved: irq=31 cpu=20 vector=0 is_managed=0


Thanks,
Song

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ