Received-SPF: pass (google.com: domain of linux-kernel-owner@vger.kernel.org designates 2620:137:e000::1:20 as permitted sender) client-ip=2620:137:e000::1:20;
Message-ID: <254cba04-0151-f7f1-1986-a8b763e940d1@samsung.com>
Date:   Tue, 15 Nov 2022 20:30:15 +0100
MIME-Version: 1.0
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:102.0)
        Gecko/20100101 Thunderbird/102.4.2
Subject: Re: [PATCH] cacheinfo: Decrement refcount in cache_setup_of_node()
Content-Language: en-US
To:     Geert Uytterhoeven <geert@linux-m68k.org>,
        Pierre Gondois <pierre.gondois@arm.com>
Cc:     linux-kernel@vger.kernel.org, Rob.Herring@arm.com,
        sudeep.holla@arm.com,
        Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
        "Rafael J. Wysocki" <rafael@kernel.org>,
        Linux-Renesas <linux-renesas-soc@vger.kernel.org>
From:   Marek Szyprowski <m.szyprowski@samsung.com>
In-Reply-To: <CAMuHMdV_rQcKVn73ywh_KcJS2uZ0xTdzGAYcTiQov4UzRouRvQ@mail.gmail.com>
Content-Transfer-Encoding: 8bit
Content-Type: text/plain; charset="utf-8"
CMS-TYPE: 201P
References: <20221026185954.991547-1-pierre.gondois@arm.com>
        <CAMuHMdV_rQcKVn73ywh_KcJS2uZ0xTdzGAYcTiQov4UzRouRvQ@mail.gmail.com>
        <CGME20221115193015eucas1p18c4b8ba131b72bc9017a14568a6a54bc@eucas1p1.samsung.com>
Precedence: bulk

Hi Geert,

On 15.11.2022 14:06, Geert Uytterhoeven wrote:
> On Wed, Oct 26, 2022 at 9:03 PM Pierre Gondois <pierre.gondois@arm.com> wrote:
>> Refcounts to DT nodes are only incremented in the function
>> and never decremented. Decrease the refcounts when necessary.
>>
>> Signed-off-by: Pierre Gondois <pierre.gondois@arm.com>
> Thanks for your patch, which is now commit 3da72e18371c41a6
> ("cacheinfo: Decrement refcount in cache_setup_of_node()") in
> driver-core-next.
>
> I have bisected a refcount underflow during s2ram to this commit:

Similar issue can be reproduced with qemu/arm64 'virt' machine during boot:

cacheinfo: Unable to detect cache hierarchy for CPU 0
------------[ cut here ]------------
refcount_t: addition on 0; use-after-free.
WARNING: CPU: 0 PID: 1 at lib/refcount.c:25 
refcount_warn_saturate+0xa0/0x144
Modules linked in:
CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.1.0-rc1+ #13076
Hardware name: linux,dummy-virt (DT)
pstate: 600000c5 (nZCv daIF -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
pc : refcount_warn_saturate+0xa0/0x144
lr : refcount_warn_saturate+0xa0/0x144
...
Call trace:
  refcount_warn_saturate+0xa0/0x144
  kobject_get+0xbc/0xc0
  of_node_get+0x20/0x34
  of_fwnode_get+0x34/0x54
  fwnode_handle_get+0x30/0x4c
  fwnode_get_nth_parent+0xec/0x104
  fwnode_full_name_string+0x48/0xc0
  device_node_string+0x278/0x530
  pointer+0x3a0/0x4bc
  vsnprintf+0x23c/0x750
  vprintk_store+0xf8/0x4a0
  vprintk_emit+0x110/0x360
  vprintk_default+0x38/0x44
  vprintk+0xc0/0xe4
  _printk+0x5c/0x84
  of_node_release+0x140/0x150
  kobject_put+0xa4/0x120
  of_node_put+0x18/0x2c
  free_cache_attributes+0x13c/0x1e0
  detect_cache_attributes+0x4f4/0x580
  update_siblings_masks+0x28/0x300
  store_cpu_topology+0x58/0x80
  smp_prepare_cpus+0x38/0x120
  kernel_init_freeable+0x1b8/0x350
  kernel_init+0x24/0x130
  ret_from_fork+0x10/0x20
irq event stamp: 74
hardirqs last  enabled at (73): [<ffffb81addf20ac0>] 
__up_console_sem+0x6c/0x70
hardirqs last disabled at (74): [<ffffb81addf22658>] 
vprintk_store+0x298/0x4a0
softirqs last  enabled at (10): [<ffffb81adde1046c>] _stext+0x46c/0x5d8
softirqs last disabled at (3): [<ffffb81adde166d0>] ____do_softirq+0x10/0x20
---[ end trace 0000000000000000 ]---


I've also observed it during the manual CPU hot plug test (the log comes 
from OdroidC4 board):

# for i in /sys/devices/system/cpu/cpu[1-8]; do echo 0 >$i/online;

psci: CPU1 killed (polled 4 ms)
------------[ cut here ]------------
refcount_t: addition on 0; use-after-free.
WARNING: CPU: 2 PID: 23 at lib/refcount.c:25 
refcount_warn_saturate+0xa0/0x144
Modules linked in: ipv6 meson_gxl dw_hdmi_i2s_audio dwmac_generic 
rc_odroid axg_audio sclk_div clk_phase mdio_mux_meson_g12a meson_ir 
snd_soc_meson_axg_tdmout snd
son_g12a_tohdmitx snd_soc_meson_codec_glue crct10dif_ce 
snd_soc_meson_axg_fifo meson_gxbb_wdt reset_meson_audio_arb pwm_meson 
meson_dw_hdmi meson_rng rtc_meson_vr
_platform snd_soc_meson_axg_sound_card drm_display_helper rng_core 
snd_soc_meson_card_utils stmmac panfrost meson_drm drm_shmem_helper 
snd_soc_meson_axg_tdm_inter
anvas nvmem_meson_efuse snd_soc_meson_axg_tdm_formatter display_connector
CPU: 2 PID: 23 Comm: cpuhp/2 Not tainted 6.1.0-rc5-next-20221115+ #5935
Hardware name: Hardkernel ODROID-C4 (DT)
pstate: 604000c9 (nZCv daIF +PAN -UAO -TCO -DIT -SSBS BTYPE=--)
pc : refcount_warn_saturate+0xa0/0x144
lr : refcount_warn_saturate+0xa0/0x144
...
Call trace:
  refcount_warn_saturate+0xa0/0x144
  kobject_get+0xbc/0xc0
  of_node_get+0x20/0x34
  of_fwnode_get+0x34/0x54
  fwnode_handle_get+0x30/0x4c
  fwnode_get_nth_parent+0xec/0x104
  fwnode_full_name_string+0x48/0xc0
  device_node_string+0x278/0x530
  pointer+0x3a0/0x4bc
  vsnprintf+0x23c/0x750
  vprintk_store+0xf8/0x4a0
  vprintk_emit+0x10c/0x35c
  vprintk_default+0x38/0x44
  vprintk+0xc0/0xe4
  _printk+0x5c/0x84
  of_node_release+0x140/0x150
  kobject_put+0xa4/0x120
  of_node_put+0x18/0x2c
  free_cache_attributes+0x13c/0x1e0
  cacheinfo_cpu_pre_down+0x80/0x90
  cpuhp_invoke_callback+0x16c/0x2b0
  cpuhp_thread_fun+0x18c/0x250
  smpboot_thread_fn+0x1f4/0x2a0
  kthread+0x118/0x11c
  ret_from_fork+0x10/0x20
irq event stamp: 204
hardirqs last  enabled at (203): [<ffff800008330260>] 
put_cpu_partial+0x1bc/0x1fc
hardirqs last disabled at (204): [<ffff8000081247ac>] 
vprintk_store+0x298/0x4a0
softirqs last  enabled at (16): [<ffff80000801046c>] _stext+0x46c/0x5d8
softirqs last disabled at (3): [<ffff800008016700>] ____do_softirq+0x10/0x20
---[ end trace 0000000000000000 ]---


Best regards
-- 
Marek Szyprowski, PhD
Samsung R&D Institute Poland