Re: [PATCH v8 17/18] scsi: megaraid_sas: Added support for shared host tagset for cpuhotplug

Sumit Saxena
2020-11-11T07:28:34Z

On Tue, Nov 10, 2020 at 11:12 PM John Garry <john.garry@huawei.com> wrote:
>
> On 09/11/2020 14:05, John Garry wrote:
> > On 09/11/2020 13:39, Qian Cai wrote:
> >>> I suppose I could try do this myself also, but an authentic version
> >>> would be nicer.
> >> The closest one I have here is:
> >> https://cailca.coding.net/public/linux/mm/git/files/master/arm64.config
> >>
> >> but it only selects the Thunder X2 platform and needs to manually select
> >> CONFIG_MEGARAID_SAS=m to start with, but none of arm64 systems here have
> >> megaraid_sas.
> >
> > Thanks, I'm confident I can fix it up to get it going on my Huawei arm64
> > D06CS.
> >
> > So that board has a megaraid sas card. In addition, it also has hisi_sas
> > HW, which is another storage controller which we enabled this same
> > feature which is causing the problem.
> >
> > I'll report back when I can.
>
> So I had to hack that arm64 config a bit to get it booting:
> https://github.com/hisilicon/kernel-dev/commits/private-topic-sas-5.10-megaraid-hang
>
> Boot is ok on my board without the megaraid sas card, but includes
> hisi_sas HW (which enables the equivalent option which is exposing the
> problem).
>
> But the board with the megaraid sas boots very slowly, specifically
> around the megaraid sas probe:
>
> : ttyS0 at MMIO 0x3f00002f8 (irq = 17, base_baud = 115200) is a 16550A
> [ 50.023726][ T1] printk: console [ttyS0] enabled
> [ 50.412597][ T1] megasas: 07.714.04.00-rc1
> [ 50.436614][ T5] megaraid_sas 0000:08:00.0: FW now in Ready state
> [ 50.450079][ T5] megaraid_sas 0000:08:00.0: 63 bit DMA mask and 63
> bit consistent mask
> [ 50.467811][ T5] megaraid_sas 0000:08:00.0: firmware supports msix
> : (128)
> [ 50.845995][ T5] megaraid_sas 0000:08:00.0: requested/available
> msix 128/128
> [ 50.861476][ T5] megaraid_sas 0000:08:00.0: current msix/online
> cpus : (128/128)
> [ 50.877616][ T5] megaraid_sas 0000:08:00.0: RDPQ mode : (enabled)
> [ 50.891018][ T5] megaraid_sas 0000:08:00.0: Current firmware
> supports maximum commands: 4077 LDIO threshold: 0
> [ 51.262942][ T5] megaraid_sas 0000:08:00.0: Performance mode
> :Latency (latency index = 1)
> [ 51.280749][ T5] megaraid_sas 0000:08:00.0: FW supports sync cache
> : Yes
> [ 51.295451][ T5] megaraid_sas 0000:08:00.0:
> megasas_disable_intr_fusion is called outbound_intr_mask:0x40000009
> [ 51.387474][ T5] megaraid_sas 0000:08:00.0: FW provided
> supportMaxExtLDs: 1 max_lds: 64
> [ 51.404931][ T5] megaraid_sas 0000:08:00.0: controller type
> : MR(2048MB)
> [ 51.419616][ T5] megaraid_sas 0000:08:00.0: Online Controller
> Reset(OCR) : Enabled
> [ 51.436132][ T5] megaraid_sas 0000:08:00.0: Secure JBOD support
> : Yes
> [ 51.450265][ T5] megaraid_sas 0000:08:00.0: NVMe passthru support
> : Yes
> [ 51.464757][ T5] megaraid_sas 0000:08:00.0: FW provided TM
> TaskAbort/Reset timeout : 6 secs/60 secs
> [ 51.484379][ T5] megaraid_sas 0000:08:00.0: JBOD sequence map
> support : Yes
> [ 51.499607][ T5] megaraid_sas 0000:08:00.0: PCI Lane Margining
> support : No
> [ 51.547610][ T5] megaraid_sas 0000:08:00.0: NVME page size
> : (4096)
> [ 51.608635][ T5] megaraid_sas 0000:08:00.0:
> megasas_enable_intr_fusion is called outbound_intr_mask:0x40000000
> [ 51.630285][ T5] megaraid_sas 0000:08:00.0: INIT adapter done
> [ 51.649854][ T5] megaraid_sas 0000:08:00.0: pci id
> : (0x1000)/(0x0016)/(0x19e5)/(0xd215)
> [ 51.667873][ T5] megaraid_sas 0000:08:00.0: unevenspan support : no
> [ 51.681646][ T5] megaraid_sas 0000:08:00.0: firmware crash dump : no
> [ 51.695596][ T5] megaraid_sas 0000:08:00.0: JBOD sequence map
> : enabled
> [ 51.711521][ T5] megaraid_sas 0000:08:00.0: Max firmware commands:
> 4076 shared with nr_hw_queues = 127
> [ 51.733056][ T5] scsi host0: Avago SAS based MegaRAID driver
> [ 65.304363][ T5] scsi 0:0:0:0: Direct-Access ATA SAMSUNG
> MZ7KH1T9 404Q PQ: 0 ANSI: 6
> [ 65.392401][ T5] scsi 0:0:1:0: Direct-Access ATA SAMSUNG
> MZ7KH1T9 404Q PQ: 0 ANSI: 6
> [ 79.508307][ T5] scsi 0:0:65:0: Enclosure HUAWEI
> Expander 12Gx16 131 PQ: 0 ANSI: 6
> [ 183.965109][ C14] random: fast init done
>
> Notice the 14 and 104 second delays.
>
> But does boot fully to get to the console. I'll wait for further issues,
> which you guys seem to experience after a while.
>
> Thanks,
> John
"megaraid_sas" driver calls “scsi_scan_host()” to discover SCSI
devices. In this failure case, scsi_scan_host() is taking a long time
to complete, hence causing delay in system boot.
With "host_tagset" enabled, scsi_scan_host() takes around 20 mins.
With "host_tagset" disabled, scsi_scan_host() takes upto 5-8 mins.

The scan time depends upon the number of scsi channels and devices per
scsi channel is exposed by LLD.
megaraid_sas driver exposes 4 channels and 128 drives per channel.

Each target scan takes 2 seconds (in case of failure with host_tagset
enabled). That's why driver load completes after ~20 minutes. See
below:

[ 299.725271] kobject: 'target18:0:96': free name
[ 301.681267] kobject: 'target18:0:97' (00000000987c7f11):
kobject_cleanup, parent 0000000000000000
[ 301.681269] kobject: 'target18:0:97' (00000000987c7f11): calling
ktype release
[ 301.681273] kobject: 'target18:0:97': free name
[ 303.575268] kobject: 'target18:0:98' (00000000a8c34149):
kobject_cleanup, parent 0000000000000000

In Qian's kernel .config, async scsi scan is disabled so in failure
case SCSI scan type is synchronous.
Below is the stack trace when scsi_scan_host() hangs:

[<0>] __wait_rcu_gp+0x134/0x170
[<0>] synchronize_rcu.part.80+0x53/0x60
[<0>] blk_free_flush_queue+0x12/0x30
[<0>] blk_mq_hw_sysfs_release+0x21/0x70
[<0>] kobject_release+0x46/0x150
[<0>] blk_mq_release+0xb4/0xf0
[<0>] blk_release_queue+0xc4/0x130
[<0>] kobject_release+0x46/0x150
[<0>] scsi_device_dev_release_usercontext+0x194/0x3f0
[<0>] execute_in_process_context+0x22/0xa0
[<0>] device_release+0x2e/0x80
[<0>] kobject_release+0x46/0x150
[<0>] scsi_alloc_sdev+0x2e7/0x310
[<0>] scsi_probe_and_add_lun+0x410/0xbd0
[<0>] __scsi_scan_target+0xf2/0x530
[<0>] scsi_scan_channel.part.7+0x51/0x70
[<0>] scsi_scan_host_selected+0xd4/0x140
[<0>] scsi_scan_host+0x198/0x1c0

This issue hits when lock related debugging is enabled in kernel config.
kernel .config parameters(may be subset of this list) are required to
hit the issue:

CONFIG_PREEMPT_COUNT=y
CONFIG_UNINLINE_SPIN_UNLOCK=y
CONFIG_LOCK_STAT=y
CONFIG_DEBUG_RT_MUTEXES=y
CONFIG_DEBUG_SPINLOCK=y
CONFIG_DEBUG_MUTEXES=y
CONFIG_DEBUG_WW_MUTEX_SLOWPATH=y
CONFIG_DEBUG_RWSEMS=y
CONFIG_DEBUG_LOCK_ALLOC=y
CONFIG_LOCKDEP=y
CONFIG_DEBUG_LOCKDEP=y
CONFIG_TRACE_IRQFLAGS=y
CONFIG_TRACE_IRQFLAGS_NMI=y
CONFIG_DEBUG_KOBJECT=y
CONFIG_PROVE_RCU=y
CONFIG_PREEMPTIRQ_TRACEPOINTS=y

When scsi_scan_host() hangs, there are no outstanding IOs with
megaraid_sas driver-firmware stack as SCSI "host_busy" counter and
megaraid_sas driver's internal counter are "0".
Key takeaways:
1. Issue is observed when lock related debugging is enabled so issue
is seen in debug environment.
2. Issue seems to be related to generic shared "host_tagset" code
whenever some kind of kernel debugging is enabled. We do not see an
immediate reason to hide this issue through disabling the
"host_tagset" feature.

John,
Issue may hit on ARM platform too using Qian's .config file with other
adapters (e.g. hisi_sas) as well. So I feel disabling “host_tagset” in
megaraid_sas driver will not help. It requires debugging from the
“Entire Shared host tag feature” perspective as scsi_scan_host()
waittime aggravates when "host_tagset" is enabled. Also, I am doing
parallel debugging and if I find anything useful, I will share.

Qian,
I need full dmesg logs from your setup with
megaraid_sas.host_tagset_enable=1 and
megaraid_sas.host_tagset_enable=0. Please wait for a long time. I just
want to make sure that whatever you observe is the same as mine.

Thanks,
Sumit