On Tue, Nov 10, 2020 at 11:12 PM John Garry <john.garry@xxxxxxxxxx> 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
