2021-10-15 13:00:08

by Zheyu Ma

[permalink] [raw]
Subject: [PATCH] scsi: lpfc: Fix the misuse of the logging function

When the driver fails in lpfc_enable_pci_dev(), it will call
lpfc_printf_log(), and in a certain case the lpfc_dmp_dbg() is
eventually called, this function uses 'phba->port_list_lock', and at
this time this lock is not been initialized, which may cause a bug.

Fix this by using 'dev_printk' to replace the previous function.

The following log reveals it:

[ 32.955597 ] INFO: trying to register non-static key.
[ 32.956002 ] The code is fine but needs lockdep annotation, or maybe
[ 32.956491 ] you didn't initialize this object before use?
[ 32.956916 ] turning off the locking correctness validator.
[ 32.958801 ] Call Trace:
[ 32.958994 ] dump_stack_lvl+0xa8/0xd1
[ 32.959286 ] dump_stack+0x15/0x17
[ 32.959547 ] assign_lock_key+0x212/0x220
[ 32.959853 ] ? SOFTIRQ_verbose+0x10/0x10
[ 32.960158 ] ? lock_is_held_type+0xd6/0x130
[ 32.960483 ] register_lock_class+0x126/0x790
[ 32.960815 ] ? rcu_read_lock_sched_held+0x33/0x70
[ 32.961233 ] __lock_acquire+0xe9/0x1e20
[ 32.961565 ] ? delete_node+0x71e/0x790
[ 32.961859 ] ? __this_cpu_preempt_check+0x13/0x20
[ 32.962220 ] ? lock_is_held_type+0xd6/0x130
[ 32.962545 ] lock_acquire+0x244/0x490
[ 32.962831 ] ? lpfc_dmp_dbg+0x65/0x600 [lpfc]
[ 32.963241 ] ? __kasan_check_write+0x14/0x20
[ 32.963572 ] ? read_lock_is_recursive+0x20/0x20
[ 32.963921 ] ? __this_cpu_preempt_check+0x13/0x20
[ 32.964284 ] ? lpfc_dmp_dbg+0x65/0x600 [lpfc]
[ 32.964685 ] ? _raw_spin_lock_irqsave+0x29/0x70
[ 32.965086 ] ? __kasan_check_read+0x11/0x20
[ 32.965410 ] ? trace_irq_disable_rcuidle+0x85/0x170
[ 32.965787 ] _raw_spin_lock_irqsave+0x4e/0x70
[ 32.966124 ] ? lpfc_dmp_dbg+0x65/0x600 [lpfc]
[ 32.966526 ] lpfc_dmp_dbg+0x65/0x600 [lpfc]
[ 32.966913 ] ? lockdep_init_map_type+0x162/0x710
[ 32.967269 ] ? error_prone+0x25/0x30 [lpfc]
[ 32.967657 ] lpfc_enable_pci_dev+0x157/0x250 [lpfc]

Signed-off-by: Zheyu Ma <[email protected]>
---
drivers/scsi/lpfc/lpfc_init.c | 12 +++++-------
drivers/scsi/lpfc/lpfc_scsi.c | 5 ++---
drivers/scsi/lpfc/lpfc_sli.c | 10 ++++------
3 files changed, 11 insertions(+), 16 deletions(-)

diff --git a/drivers/scsi/lpfc/lpfc_init.c b/drivers/scsi/lpfc/lpfc_init.c
index 0ec322f0e3cb..226b9ccfffb3 100644
--- a/drivers/scsi/lpfc/lpfc_init.c
+++ b/drivers/scsi/lpfc/lpfc_init.c
@@ -7331,10 +7331,10 @@ static void lpfc_log_intr_mode(struct lpfc_hba *phba, uint32_t intr_mode)
static int
lpfc_enable_pci_dev(struct lpfc_hba *phba)
{
- struct pci_dev *pdev;
+ struct pci_dev *pdev = phba->pcidev;

/* Obtain PCI device reference */
- if (!phba->pcidev)
+ if (!pdev)
goto out_error;
else
pdev = phba->pcidev;
@@ -7358,8 +7358,7 @@ lpfc_enable_pci_dev(struct lpfc_hba *phba)
out_disable_device:
pci_disable_device(pdev);
out_error:
- lpfc_printf_log(phba, KERN_ERR, LOG_TRACE_EVENT,
- "1401 Failed to enable pci device\n");
+ dev_err(&pdev->dev, "1401 Failed to enable pci device\n");
return -ENODEV;
}

@@ -8401,9 +8400,8 @@ lpfc_init_api_table_setup(struct lpfc_hba *phba, uint8_t dev_grp)
phba->lpfc_stop_port = lpfc_stop_port_s4;
break;
default:
- lpfc_printf_log(phba, KERN_ERR, LOG_TRACE_EVENT,
- "1431 Invalid HBA PCI-device group: 0x%x\n",
- dev_grp);
+ dev_err(&phba->pcidev->dev,
+ "1431 Invalid HBA PCI-device group: 0x%x\n", dev_grp);
return -ENODEV;
}
return 0;
diff --git a/drivers/scsi/lpfc/lpfc_scsi.c b/drivers/scsi/lpfc/lpfc_scsi.c
index 0fde1e874c7a..8ffce2d2a993 100644
--- a/drivers/scsi/lpfc/lpfc_scsi.c
+++ b/drivers/scsi/lpfc/lpfc_scsi.c
@@ -5096,9 +5096,8 @@ lpfc_scsi_api_table_setup(struct lpfc_hba *phba, uint8_t dev_grp)
phba->lpfc_scsi_prep_cmnd_buf = lpfc_scsi_prep_cmnd_buf_s4;
break;
default:
- lpfc_printf_log(phba, KERN_ERR, LOG_TRACE_EVENT,
- "1418 Invalid HBA PCI-device group: 0x%x\n",
- dev_grp);
+ dev_err(&phba->pcidev->dev,
+ "1418 Invalid HBA PCI-device group: 0x%x\n", dev_grp);
return -ENODEV;
}
phba->lpfc_rampdown_queue_depth = lpfc_rampdown_queue_depth;
diff --git a/drivers/scsi/lpfc/lpfc_sli.c b/drivers/scsi/lpfc/lpfc_sli.c
index ffd8a140638c..c1cf0ad018e0 100644
--- a/drivers/scsi/lpfc/lpfc_sli.c
+++ b/drivers/scsi/lpfc/lpfc_sli.c
@@ -10010,9 +10010,8 @@ lpfc_mbox_api_table_setup(struct lpfc_hba *phba, uint8_t dev_grp)
phba->lpfc_sli_brdready = lpfc_sli_brdready_s4;
break;
default:
- lpfc_printf_log(phba, KERN_ERR, LOG_TRACE_EVENT,
- "1420 Invalid HBA PCI-device group: 0x%x\n",
- dev_grp);
+ dev_err(&phba->pcidev->dev,
+ "1420 Invalid HBA PCI-device group: 0x%x\n", dev_grp);
return -ENODEV;
}
return 0;
@@ -11178,9 +11177,8 @@ lpfc_sli_api_table_setup(struct lpfc_hba *phba, uint8_t dev_grp)
phba->__lpfc_sli_issue_fcp_io = __lpfc_sli_issue_fcp_io_s4;
break;
default:
- lpfc_printf_log(phba, KERN_ERR, LOG_TRACE_EVENT,
- "1419 Invalid HBA PCI-device group: 0x%x\n",
- dev_grp);
+ dev_err(&phba->pcidev->dev,
+ "1419 Invalid HBA PCI-device group: 0x%x\n", dev_grp);
return -ENODEV;
}
phba->lpfc_get_iocb_from_iocbq = lpfc_get_iocb_from_iocbq;
--
2.17.6


2021-10-18 03:20:48

by James Smart

[permalink] [raw]
Subject: Re: [PATCH] scsi: lpfc: Fix the misuse of the logging function

On 10/14/2021 11:33 PM, Zheyu Ma wrote:
> When the driver fails in lpfc_enable_pci_dev(), it will call
> lpfc_printf_log(), and in a certain case the lpfc_dmp_dbg() is
> eventually called, this function uses 'phba->port_list_lock', and at
> this time this lock is not been initialized, which may cause a bug.
>
> Fix this by using 'dev_printk' to replace the previous function.
>
> The following log reveals it:
>
> [ 32.955597 ] INFO: trying to register non-static key.
> [ 32.956002 ] The code is fine but needs lockdep annotation, or maybe
> [ 32.956491 ] you didn't initialize this object before use?
> [ 32.956916 ] turning off the locking correctness validator.
> [ 32.958801 ] Call Trace:
> [ 32.958994 ] dump_stack_lvl+0xa8/0xd1
> [ 32.959286 ] dump_stack+0x15/0x17
> [ 32.959547 ] assign_lock_key+0x212/0x220
> [ 32.959853 ] ? SOFTIRQ_verbose+0x10/0x10
> [ 32.960158 ] ? lock_is_held_type+0xd6/0x130
> [ 32.960483 ] register_lock_class+0x126/0x790
> [ 32.960815 ] ? rcu_read_lock_sched_held+0x33/0x70
> [ 32.961233 ] __lock_acquire+0xe9/0x1e20
> [ 32.961565 ] ? delete_node+0x71e/0x790
> [ 32.961859 ] ? __this_cpu_preempt_check+0x13/0x20
> [ 32.962220 ] ? lock_is_held_type+0xd6/0x130
> [ 32.962545 ] lock_acquire+0x244/0x490
> [ 32.962831 ] ? lpfc_dmp_dbg+0x65/0x600 [lpfc]
> [ 32.963241 ] ? __kasan_check_write+0x14/0x20
> [ 32.963572 ] ? read_lock_is_recursive+0x20/0x20
> [ 32.963921 ] ? __this_cpu_preempt_check+0x13/0x20
> [ 32.964284 ] ? lpfc_dmp_dbg+0x65/0x600 [lpfc]
> [ 32.964685 ] ? _raw_spin_lock_irqsave+0x29/0x70
> [ 32.965086 ] ? __kasan_check_read+0x11/0x20
> [ 32.965410 ] ? trace_irq_disable_rcuidle+0x85/0x170
> [ 32.965787 ] _raw_spin_lock_irqsave+0x4e/0x70
> [ 32.966124 ] ? lpfc_dmp_dbg+0x65/0x600 [lpfc]
> [ 32.966526 ] lpfc_dmp_dbg+0x65/0x600 [lpfc]
> [ 32.966913 ] ? lockdep_init_map_type+0x162/0x710
> [ 32.967269 ] ? error_prone+0x25/0x30 [lpfc]
> [ 32.967657 ] lpfc_enable_pci_dev+0x157/0x250 [lpfc]
>
> Signed-off-by: Zheyu Ma <[email protected]>

Zheyu,

Thank you for the time and effort on this. Your points are all valid.
However, we'd like to correct this using a slightly different method.
We will post a different patch shortly for the issue.

-- james