* lpfc on latest 5.9 is very chatty on modprobe @ 2020-09-10 16:36 Laurence Oberman 2020-09-11 15:09 ` Laurence Oberman 0 siblings, 1 reply; 4+ messages in thread From: Laurence Oberman @ 2020-09-10 16:36 UTC (permalink / raw) To: linux-scsi Hello I was testing lpfc on 5.9 and noticed a lot more logging on modprobe. Even when lpfc_log_verbose = 0 root@segstorage3 ~]# cat /sys/class/scsi_host/host*/lpfc_log_verbose 0x0 0x0 0x0 0x0 Wondered if its been there for a while and its just because I now started testing. [ 143.398194] scsi host3: Emulex LPe12000 PCIe Fibre Channel Adapter on PCI bus 0e device 00 irq 213 [ 145.598711] scsi host4: Emulex LPe12000 PCIe Fibre Channel Adapter on PCI bus 0e device 01 irq 216 [ 147.877559] lpfc 0000:0b:00.0: 2:6101 Disabling NVME support: Not supported by firmware (0 0) x3 [ 147.929264] lpfc 0000:0b:00.0: 2:2574 IO channels: hdwQ 64 IRQ 64 MRQ: 0 [ 147.974727] scsi host5: Emulex LPe16000 16Gb PCIe Fibre Channel Adapter on PCI bus 0b device 00 irq 219 PCI resettable [ 149.156406] lpfc 0000:0b:00.0: 2:3176 Port Name 0 Physical Link is functional [ 149.284537] lpfc 0000:0b:00.1: 3:6101 Disabling NVME support: Not supported by firmware (0 0) x3 [ 149.336809] lpfc 0000:0b:00.1: 3:2574 IO channels: hdwQ 64 IRQ 64 MRQ: 0 [ 149.388033] scsi host6: Emulex LPe16000 16Gb PCIe Fibre Channel Adapter on PCI bus 0b device 01 irq 284 PCI resettable [ 150.848392] lpfc 0000:0b:00.1: 3:3176 Port Name 1 Physical Link is functional [ 151.477690] lpfc 0000:0b:00.0: 2:1303 Link Up Event x1 received Data: x1 x0 x20 x0 x0 x0 0 [ 151.526732] lpfc 0000:0b:00.0: start 183 end 182 cnt 256 [ 151.559193] lpfc 0000:0b:00.0: 183: [ 148.759023] 2:2593 WQ setup: wq[35]-id=35 assoc=35, cq[35]-id=35 [ 151.617510] lpfc 0000:0b:00.0: 184: [ 148.763089] 2:(0):0356 Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 x4 x24 xb8000000 x24 x1000 CQ: x0 x0 x0 x90000000 [ 151.715751] lpfc 0000:0b:00.0: 185: [ 148.763090] 2:6087 CQ setup: cq[36]-id=36, parent eq[36]-id=36 [ 151.772034] lpfc 0000:0b:00.0: 186: [ 148.767155] 2:(0):0356 Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 x4 x4 x240024 x4008504 x0 xcf400000 CQ: x0 x0 x0 x90000000 [ 151.872722] lpfc 0000:0b:00.0: 187: [ 148.767156] 2:2593 WQ setup: wq[36]-id=36 assoc=36, cq[36]-id=36 [ 151.929396] lpfc 0000:0b:00.0: 188: [ 148.771220] 2:(0):0356 Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 x4 x25 xb8000000 x25 x1000 CQ: x0 x0 x0 x90000000 [ 152.030050] lpfc 0000:0b:00.0: 189: [ 148.771221] 2:6087 CQ setup: cq[37]-id=37, parent eq[37]-id=37 [ 152.085622] lpfc 0000:0b:00.0: 190: [ 148.775285] 2:(0):0356 Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 x4 x4 x250025 x4008504 x0 xbc7e0000 CQ: x0 x0 x0 x90000000 [ 152.185681] lpfc 0000:0b:00.0: 191: [ 148.775287] 2:2593 WQ setup: wq[37]-id=37 assoc=37, cq[37]-id=37 [ 152.243645] lpfc 0000:0b:00.0: 192: [ 148.779351] 2:(0):0356 Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 x4 x26 xb8000000 x26 x1000 CQ: x0 x0 x0 x90000000 [ 152.341442] lpfc 0000:0b:00.0: 193: [ 148.779352] 2:6087 CQ setup: cq[38]-id=38, parent eq[38]-id=38 [ 152.399734] lpfc 0000:0b:00.0: 194: [ 148.783416] 2:(0):0356 Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 x4 x4 x260026 x4008504 x0 x5ef40000 CQ: x0 x0 x0 x90000000 [ 152.501390] lpfc 0000:0b:00.0: 195: [ 148.783417] 2:2593 WQ setup: wq[38]-id=38 assoc=38, cq[38]-id=38 [ 152.557531] lpfc 0000:0b:00.0: 196: [ 148.787481] 2:(0):0356 Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 x4 x27 xb8000000 x27 x1000 CQ: x0 x0 x0 x90000000 .. .. [ 190.872503] lpfc 0000:0b:00.0: start 109 end 115 cnt 6 [ 190.872506] lpfc 0000:0b:00.0: 109: [ 190.871058] 2:(0):0117 Xmit ELS response x1 to remote NPORT x20300 I/O tag: xb92, size: x8 port_state x20 rpi x10 fc_flag x800110 [ 190.872507] lpfc 0000:0b:00.0: 110: [ 190.871060] 2:(0):0129 Xmit ELS RJT xb00 response tag xb92 xri xffff, did x20300, nlp_flag x80000000, nlp_state x7, rpi x10 [ 190.872509] lpfc 0000:0b:00.0: 111: [ 190.871085] 2:(0):0110 ELS response tag xb92 completes Data: x0 x0 x0 x20300 x80000000 x7 x10 [ 190.872511] lpfc 0000:0b:00.0: 112: [ 190.872497] 2:2538 Received frame rctl:x22, type:x1, frame Data:220a0300 00010600 01290000 00000000 0048ffff 00000000 00000000 [ 190.872512] lpfc 0000:0b:00.0: 113: [ 190.872500] 2:(0):0929 FIND node DID Data: xffff896e4faf2c00 x10600 x80000000 x7001801 xc xffff896e4faf1200 [ 190.872514] lpfc 0000:0b:00.0: 114: [ 190.872501] 2:(0):0112 ELS command x14001023 received from NPORT x10600 Data: x20 x800110 xa0300 xa0300 [ 190.872515] lpfc 0000:0b:00.0: 2:(0):0115 Unknown ELS command x14001023 received from NPORT x10600 [ 190.873239] lpfc 0000:0b:00.0: start 115 end 121 cnt 6 [ 190.873241] lpfc 0000:0b:00.0: 115: [ 190.872517] 2:(0):0117 Xmit ELS response x1 to remote NPORT x10600 I/O tag: xb8f, size: x8 port_state x20 rpi xc fc_flag x800110 [ 190.873243] lpfc 0000:0b:00.0: 116: [ 190.872519] 2:(0):0129 Xmit ELS RJT xb00 response tag xb8f xri xffff, did x10600, nlp_flag x80000000, nlp_state x7, rpi xc [ 190.873244] lpfc 0000:0b:00.0: 117: [ 190.872545] 2:(0):0110 ELS response tag xb8f completes Data: x0 x0 x0 x10600 x80000000 x7 xc [ 190.873246] lpfc 0000:0b:00.0: 118: [ 190.873234] 2:2538 Received frame rctl:x22, type:x1, frame Data:220a0300 00010700 01290000 00000000 008cffff 00000000 00000000 [ 190.873249] lpfc 0000:0b:00.0: 119: [ 190.873236] 2:(0):0929 FIND node DID Data: xffff896e4faf0600 x10700 x80000000 x7001801 xd xffff896e4faf3600 I have not investogated the masking changes yet, decided to first ask. Thanks Laurence ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: lpfc on latest 5.9 is very chatty on modprobe 2020-09-10 16:36 lpfc on latest 5.9 is very chatty on modprobe Laurence Oberman @ 2020-09-11 15:09 ` Laurence Oberman 2020-09-11 15:55 ` Laurence Oberman 0 siblings, 1 reply; 4+ messages in thread From: Laurence Oberman @ 2020-09-11 15:09 UTC (permalink / raw) To: linux-scsi; +Cc: dick Kennedy, Ewan Milne On Thu, 2020-09-10 at 12:36 -0400, Laurence Oberman wrote: > Hello > > I was testing lpfc on 5.9 and noticed a lot more logging on modprobe. > Even when lpfc_log_verbose = 0 > > root@segstorage3 ~]# cat /sys/class/scsi_host/host*/lpfc_log_verbose > 0x0 > 0x0 > 0x0 > 0x0 > > Wondered if its been there for a while and its just because I now > started testing. > > [ 143.398194] scsi host3: Emulex LPe12000 PCIe Fibre Channel Adapter > on PCI bus 0e device 00 irq 213 > [ 145.598711] scsi host4: Emulex LPe12000 PCIe Fibre Channel Adapter > on PCI bus 0e device 01 irq 216 > [ 147.877559] lpfc 0000:0b:00.0: 2:6101 Disabling NVME support: Not > supported by firmware (0 0) x3 > [ 147.929264] lpfc 0000:0b:00.0: 2:2574 IO channels: hdwQ 64 IRQ 64 > MRQ: 0 > [ 147.974727] scsi host5: Emulex LPe16000 16Gb PCIe Fibre Channel > Adapter on PCI bus 0b device 00 irq 219 PCI resettable > [ 149.156406] lpfc 0000:0b:00.0: 2:3176 Port Name 0 Physical Link is > functional > [ 149.284537] lpfc 0000:0b:00.1: 3:6101 Disabling NVME support: Not > supported by firmware (0 0) x3 > [ 149.336809] lpfc 0000:0b:00.1: 3:2574 IO channels: hdwQ 64 IRQ 64 > MRQ: 0 > [ 149.388033] scsi host6: Emulex LPe16000 16Gb PCIe Fibre Channel > Adapter on PCI bus 0b device 01 irq 284 PCI resettable > [ 150.848392] lpfc 0000:0b:00.1: 3:3176 Port Name 1 Physical Link is > functional > [ 151.477690] lpfc 0000:0b:00.0: 2:1303 Link Up Event x1 received > Data: x1 x0 x20 x0 x0 x0 0 > [ 151.526732] lpfc 0000:0b:00.0: start 183 end 182 cnt 256 > [ 151.559193] lpfc 0000:0b:00.0: 183: [ 148.759023] 2:2593 WQ > setup: > wq[35]-id=35 assoc=35, cq[35]-id=35 > [ 151.617510] lpfc 0000:0b:00.0: 184: [ 148.763089] 2:(0):0356 > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 x4 > x24 xb8000000 x24 x1000 CQ: x0 x0 x0 x90000000 > [ 151.715751] lpfc 0000:0b:00.0: 185: [ 148.763090] 2:6087 CQ > setup: > cq[36]-id=36, parent eq[36]-id=36 > [ 151.772034] lpfc 0000:0b:00.0: 186: [ 148.767155] 2:(0):0356 > Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 x4 x4 > x240024 x4008504 x0 xcf400000 CQ: x0 x0 x0 x90000000 > [ 151.872722] lpfc 0000:0b:00.0: 187: [ 148.767156] 2:2593 WQ > setup: > wq[36]-id=36 assoc=36, cq[36]-id=36 > [ 151.929396] lpfc 0000:0b:00.0: 188: [ 148.771220] 2:(0):0356 > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 x4 > x25 xb8000000 x25 x1000 CQ: x0 x0 x0 x90000000 > [ 152.030050] lpfc 0000:0b:00.0: 189: [ 148.771221] 2:6087 CQ > setup: > cq[37]-id=37, parent eq[37]-id=37 > [ 152.085622] lpfc 0000:0b:00.0: 190: [ 148.775285] 2:(0):0356 > Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 x4 x4 > x250025 x4008504 x0 xbc7e0000 CQ: x0 x0 x0 x90000000 > [ 152.185681] lpfc 0000:0b:00.0: 191: [ 148.775287] 2:2593 WQ > setup: > wq[37]-id=37 assoc=37, cq[37]-id=37 > [ 152.243645] lpfc 0000:0b:00.0: 192: [ 148.779351] 2:(0):0356 > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 x4 > x26 xb8000000 x26 x1000 CQ: x0 x0 x0 x90000000 > [ 152.341442] lpfc 0000:0b:00.0: 193: [ 148.779352] 2:6087 CQ > setup: > cq[38]-id=38, parent eq[38]-id=38 > [ 152.399734] lpfc 0000:0b:00.0: 194: [ 148.783416] 2:(0):0356 > Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 x4 x4 > x260026 x4008504 x0 x5ef40000 CQ: x0 x0 x0 x90000000 > [ 152.501390] lpfc 0000:0b:00.0: 195: [ 148.783417] 2:2593 WQ > setup: > wq[38]-id=38 assoc=38, cq[38]-id=38 > [ 152.557531] lpfc 0000:0b:00.0: 196: [ 148.787481] 2:(0):0356 > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 x4 > x27 xb8000000 x27 x1000 CQ: x0 x0 x0 x90000000 > .. > .. > [ 190.872503] lpfc 0000:0b:00.0: start 109 end 115 cnt 6 > [ 190.872506] lpfc 0000:0b:00.0: 109: [ 190.871058] 2:(0):0117 Xmit > ELS response x1 to remote NPORT x20300 I/O tag: xb92, size: x8 > port_state x20 rpi x10 fc_flag x800110 > [ 190.872507] lpfc 0000:0b:00.0: 110: [ 190.871060] 2:(0):0129 Xmit > ELS RJT xb00 response tag xb92 xri xffff, did x20300, nlp_flag > x80000000, nlp_state x7, rpi x10 > [ 190.872509] lpfc 0000:0b:00.0: 111: [ 190.871085] 2:(0):0110 ELS > response tag xb92 completes Data: x0 x0 x0 x20300 x80000000 x7 x10 > [ 190.872511] lpfc 0000:0b:00.0: 112: [ 190.872497] 2:2538 Received > frame rctl:x22, type:x1, frame Data:220a0300 00010600 01290000 > 00000000 > 0048ffff 00000000 00000000 > [ 190.872512] lpfc 0000:0b:00.0: 113: [ 190.872500] 2:(0):0929 FIND > node DID Data: xffff896e4faf2c00 x10600 x80000000 x7001801 xc > xffff896e4faf1200 > [ 190.872514] lpfc 0000:0b:00.0: 114: [ 190.872501] 2:(0):0112 ELS > command x14001023 received from NPORT x10600 Data: x20 x800110 xa0300 > xa0300 > [ 190.872515] lpfc 0000:0b:00.0: 2:(0):0115 Unknown ELS command > x14001023 received from NPORT x10600 > [ 190.873239] lpfc 0000:0b:00.0: start 115 end 121 cnt 6 > [ 190.873241] lpfc 0000:0b:00.0: 115: [ 190.872517] 2:(0):0117 Xmit > ELS response x1 to remote NPORT x10600 I/O tag: xb8f, size: x8 > port_state x20 rpi xc fc_flag x800110 > [ 190.873243] lpfc 0000:0b:00.0: 116: [ 190.872519] 2:(0):0129 Xmit > ELS RJT xb00 response tag xb8f xri xffff, did x10600, nlp_flag > x80000000, nlp_state x7, rpi xc > [ 190.873244] lpfc 0000:0b:00.0: 117: [ 190.872545] 2:(0):0110 ELS > response tag xb8f completes Data: x0 x0 x0 x10600 x80000000 x7 xc > [ 190.873246] lpfc 0000:0b:00.0: 118: [ 190.873234] 2:2538 Received > frame rctl:x22, type:x1, frame Data:220a0300 00010700 01290000 > 00000000 > 008cffff 00000000 00000000 > [ 190.873249] lpfc 0000:0b:00.0: 119: [ 190.873236] 2:(0):0929 FIND > node DID Data: xffff896e4faf0600 x10700 x80000000 x7001801 xd > xffff896e4faf3600 > > I have not investogated the masking changes yet, decided to first > ask. > > Thanks > Laurence Hi Dick I dont see this when booting 5.5, which was when I last tested, and before I start the long arduous code review and maybe bisect I would rather have you look at it. Can you look at this please and let me know. Its not happeniong on latest RHEL8 but could happen if we take latest code in. Regards Laurence ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: lpfc on latest 5.9 is very chatty on modprobe 2020-09-11 15:09 ` Laurence Oberman @ 2020-09-11 15:55 ` Laurence Oberman [not found] ` <CAGx+d6dhGuJdUfisgvVfaTJ5aT7D9hP+WQcaD485iF=tuKqv7w@mail.gmail.com> 0 siblings, 1 reply; 4+ messages in thread From: Laurence Oberman @ 2020-09-11 15:55 UTC (permalink / raw) To: linux-scsi; +Cc: dick Kennedy, Ewan Milne On Fri, 2020-09-11 at 11:09 -0400, Laurence Oberman wrote: > On Thu, 2020-09-10 at 12:36 -0400, Laurence Oberman wrote: > > Hello > > > > I was testing lpfc on 5.9 and noticed a lot more logging on > > modprobe. > > Even when lpfc_log_verbose = 0 > > > > root@segstorage3 ~]# cat > > /sys/class/scsi_host/host*/lpfc_log_verbose > > 0x0 > > 0x0 > > 0x0 > > 0x0 > > > > Wondered if its been there for a while and its just because I now > > started testing. > > > > [ 143.398194] scsi host3: Emulex LPe12000 PCIe Fibre Channel > > Adapter > > on PCI bus 0e device 00 irq 213 > > [ 145.598711] scsi host4: Emulex LPe12000 PCIe Fibre Channel > > Adapter > > on PCI bus 0e device 01 irq 216 > > [ 147.877559] lpfc 0000:0b:00.0: 2:6101 Disabling NVME support: > > Not > > supported by firmware (0 0) x3 > > [ 147.929264] lpfc 0000:0b:00.0: 2:2574 IO channels: hdwQ 64 IRQ > > 64 > > MRQ: 0 > > [ 147.974727] scsi host5: Emulex LPe16000 16Gb PCIe Fibre Channel > > Adapter on PCI bus 0b device 00 irq 219 PCI resettable > > [ 149.156406] lpfc 0000:0b:00.0: 2:3176 Port Name 0 Physical Link > > is > > functional > > [ 149.284537] lpfc 0000:0b:00.1: 3:6101 Disabling NVME support: > > Not > > supported by firmware (0 0) x3 > > [ 149.336809] lpfc 0000:0b:00.1: 3:2574 IO channels: hdwQ 64 IRQ > > 64 > > MRQ: 0 > > [ 149.388033] scsi host6: Emulex LPe16000 16Gb PCIe Fibre Channel > > Adapter on PCI bus 0b device 01 irq 284 PCI resettable > > [ 150.848392] lpfc 0000:0b:00.1: 3:3176 Port Name 1 Physical Link > > is > > functional > > [ 151.477690] lpfc 0000:0b:00.0: 2:1303 Link Up Event x1 received > > Data: x1 x0 x20 x0 x0 x0 0 > > [ 151.526732] lpfc 0000:0b:00.0: start 183 end 182 cnt 256 > > [ 151.559193] lpfc 0000:0b:00.0: 183: [ 148.759023] 2:2593 WQ > > setup: > > wq[35]-id=35 assoc=35, cq[35]-id=35 > > [ 151.617510] lpfc 0000:0b:00.0: 184: [ 148.763089] 2:(0):0356 > > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 > > x4 > > x24 xb8000000 x24 x1000 CQ: x0 x0 x0 x90000000 > > [ 151.715751] lpfc 0000:0b:00.0: 185: [ 148.763090] 2:6087 CQ > > setup: > > cq[36]-id=36, parent eq[36]-id=36 > > [ 151.772034] lpfc 0000:0b:00.0: 186: [ 148.767155] 2:(0):0356 > > Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 x4 > > x4 > > x240024 x4008504 x0 xcf400000 CQ: x0 x0 x0 x90000000 > > [ 151.872722] lpfc 0000:0b:00.0: 187: [ 148.767156] 2:2593 WQ > > setup: > > wq[36]-id=36 assoc=36, cq[36]-id=36 > > [ 151.929396] lpfc 0000:0b:00.0: 188: [ 148.771220] 2:(0):0356 > > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 > > x4 > > x25 xb8000000 x25 x1000 CQ: x0 x0 x0 x90000000 > > [ 152.030050] lpfc 0000:0b:00.0: 189: [ 148.771221] 2:6087 CQ > > setup: > > cq[37]-id=37, parent eq[37]-id=37 > > [ 152.085622] lpfc 0000:0b:00.0: 190: [ 148.775285] 2:(0):0356 > > Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 x4 > > x4 > > x250025 x4008504 x0 xbc7e0000 CQ: x0 x0 x0 x90000000 > > [ 152.185681] lpfc 0000:0b:00.0: 191: [ 148.775287] 2:2593 WQ > > setup: > > wq[37]-id=37 assoc=37, cq[37]-id=37 > > [ 152.243645] lpfc 0000:0b:00.0: 192: [ 148.779351] 2:(0):0356 > > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 > > x4 > > x26 xb8000000 x26 x1000 CQ: x0 x0 x0 x90000000 > > [ 152.341442] lpfc 0000:0b:00.0: 193: [ 148.779352] 2:6087 CQ > > setup: > > cq[38]-id=38, parent eq[38]-id=38 > > [ 152.399734] lpfc 0000:0b:00.0: 194: [ 148.783416] 2:(0):0356 > > Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 x4 > > x4 > > x260026 x4008504 x0 x5ef40000 CQ: x0 x0 x0 x90000000 > > [ 152.501390] lpfc 0000:0b:00.0: 195: [ 148.783417] 2:2593 WQ > > setup: > > wq[38]-id=38 assoc=38, cq[38]-id=38 > > [ 152.557531] lpfc 0000:0b:00.0: 196: [ 148.787481] 2:(0):0356 > > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 x4 > > x4 > > x27 xb8000000 x27 x1000 CQ: x0 x0 x0 x90000000 > > .. > > .. > > [ 190.872503] lpfc 0000:0b:00.0: start 109 end 115 cnt 6 > > [ 190.872506] lpfc 0000:0b:00.0: 109: [ 190.871058] 2:(0):0117 > > Xmit > > ELS response x1 to remote NPORT x20300 I/O tag: xb92, size: x8 > > port_state x20 rpi x10 fc_flag x800110 > > [ 190.872507] lpfc 0000:0b:00.0: 110: [ 190.871060] 2:(0):0129 > > Xmit > > ELS RJT xb00 response tag xb92 xri xffff, did x20300, nlp_flag > > x80000000, nlp_state x7, rpi x10 > > [ 190.872509] lpfc 0000:0b:00.0: 111: [ 190.871085] 2:(0):0110 > > ELS > > response tag xb92 completes Data: x0 x0 x0 x20300 x80000000 x7 x10 > > [ 190.872511] lpfc 0000:0b:00.0: 112: [ 190.872497] 2:2538 > > Received > > frame rctl:x22, type:x1, frame Data:220a0300 00010600 01290000 > > 00000000 > > 0048ffff 00000000 00000000 > > [ 190.872512] lpfc 0000:0b:00.0: 113: [ 190.872500] 2:(0):0929 > > FIND > > node DID Data: xffff896e4faf2c00 x10600 x80000000 x7001801 xc > > xffff896e4faf1200 > > [ 190.872514] lpfc 0000:0b:00.0: 114: [ 190.872501] 2:(0):0112 > > ELS > > command x14001023 received from NPORT x10600 Data: x20 x800110 > > xa0300 > > xa0300 > > [ 190.872515] lpfc 0000:0b:00.0: 2:(0):0115 Unknown ELS command > > x14001023 received from NPORT x10600 > > [ 190.873239] lpfc 0000:0b:00.0: start 115 end 121 cnt 6 > > [ 190.873241] lpfc 0000:0b:00.0: 115: [ 190.872517] 2:(0):0117 > > Xmit > > ELS response x1 to remote NPORT x10600 I/O tag: xb8f, size: x8 > > port_state x20 rpi xc fc_flag x800110 > > [ 190.873243] lpfc 0000:0b:00.0: 116: [ 190.872519] 2:(0):0129 > > Xmit > > ELS RJT xb00 response tag xb8f xri xffff, did x10600, nlp_flag > > x80000000, nlp_state x7, rpi xc > > [ 190.873244] lpfc 0000:0b:00.0: 117: [ 190.872545] 2:(0):0110 > > ELS > > response tag xb8f completes Data: x0 x0 x0 x10600 x80000000 x7 xc > > [ 190.873246] lpfc 0000:0b:00.0: 118: [ 190.873234] 2:2538 > > Received > > frame rctl:x22, type:x1, frame Data:220a0300 00010700 01290000 > > 00000000 > > 008cffff 00000000 00000000 > > [ 190.873249] lpfc 0000:0b:00.0: 119: [ 190.873236] 2:(0):0929 > > FIND > > node DID Data: xffff896e4faf0600 x10700 x80000000 x7001801 xd > > xffff896e4faf3600 > > > > I have not investogated the masking changes yet, decided to first > > ask. > > > > Thanks > > Laurence > > Hi Dick I dont see this when booting 5.5, which was when I last > tested, > and before I start the long arduous code review and maybe bisect I > would rather have you look at it. > Can you look at this please and let me know. > Its not happeniong on latest RHEL8 but could happen if we take latest > code in. > > Regards > Laurence > Dick Seems to be all these changes like below. all chamhed to LOG_TRACE_EVENT - lpfc_printf_vlog(vport, KERN_ERR, LOG_INIT | LOG_VPORT, + lpfc_printf_vlog(vport, KERN_ERR, LOG_TRACE_EVENT, ^ permalink raw reply [flat|nested] 4+ messages in thread
[parent not found: <CAGx+d6dhGuJdUfisgvVfaTJ5aT7D9hP+WQcaD485iF=tuKqv7w@mail.gmail.com>]
* Re: lpfc on latest 5.9 is very chatty on modprobe [not found] ` <CAGx+d6dhGuJdUfisgvVfaTJ5aT7D9hP+WQcaD485iF=tuKqv7w@mail.gmail.com> @ 2020-09-11 19:18 ` Laurence Oberman 0 siblings, 0 replies; 4+ messages in thread From: Laurence Oberman @ 2020-09-11 19:18 UTC (permalink / raw) To: Dick Kennedy; +Cc: linux-scsi, Ewan Milne On Fri, 2020-09-11 at 13:57 -0400, Dick Kennedy wrote: > Yes we have been removing some of those trace events to eliminate the > false logs. > > All of the successful scsi task management commands will generate > false logs. We have a patch for that coming. > All of the successful vport deletes will also generate the false > logs. > > But other than that I can say that having it in there has made my > life a little easier. > > > On Fri, Sep 11, 2020 at 11:55 AM Laurence Oberman < > loberman@redhat.com> wrote: > > On Fri, 2020-09-11 at 11:09 -0400, Laurence Oberman wrote: > > > On Thu, 2020-09-10 at 12:36 -0400, Laurence Oberman wrote: > > > > Hello > > > > > > > > I was testing lpfc on 5.9 and noticed a lot more logging on > > > > modprobe. > > > > Even when lpfc_log_verbose = 0 > > > > > > > > root@segstorage3 ~]# cat > > > > /sys/class/scsi_host/host*/lpfc_log_verbose > > > > 0x0 > > > > 0x0 > > > > 0x0 > > > > 0x0 > > > > > > > > Wondered if its been there for a while and its just because I > > now > > > > started testing. > > > > > > > > [ 143.398194] scsi host3: Emulex LPe12000 PCIe Fibre Channel > > > > Adapter > > > > on PCI bus 0e device 00 irq 213 > > > > [ 145.598711] scsi host4: Emulex LPe12000 PCIe Fibre Channel > > > > Adapter > > > > on PCI bus 0e device 01 irq 216 > > > > [ 147.877559] lpfc 0000:0b:00.0: 2:6101 Disabling NVME > > support: > > > > Not > > > > supported by firmware (0 0) x3 > > > > [ 147.929264] lpfc 0000:0b:00.0: 2:2574 IO channels: hdwQ 64 > > IRQ > > > > 64 > > > > MRQ: 0 > > > > [ 147.974727] scsi host5: Emulex LPe16000 16Gb PCIe Fibre > > Channel > > > > Adapter on PCI bus 0b device 00 irq 219 PCI resettable > > > > [ 149.156406] lpfc 0000:0b:00.0: 2:3176 Port Name 0 Physical > > Link > > > > is > > > > functional > > > > [ 149.284537] lpfc 0000:0b:00.1: 3:6101 Disabling NVME > > support: > > > > Not > > > > supported by firmware (0 0) x3 > > > > [ 149.336809] lpfc 0000:0b:00.1: 3:2574 IO channels: hdwQ 64 > > IRQ > > > > 64 > > > > MRQ: 0 > > > > [ 149.388033] scsi host6: Emulex LPe16000 16Gb PCIe Fibre > > Channel > > > > Adapter on PCI bus 0b device 01 irq 284 PCI resettable > > > > [ 150.848392] lpfc 0000:0b:00.1: 3:3176 Port Name 1 Physical > > Link > > > > is > > > > functional > > > > [ 151.477690] lpfc 0000:0b:00.0: 2:1303 Link Up Event x1 > > received > > > > Data: x1 x0 x20 x0 x0 x0 0 > > > > [ 151.526732] lpfc 0000:0b:00.0: start 183 end 182 cnt 256 > > > > [ 151.559193] lpfc 0000:0b:00.0: 183: [ 148.759023] 2:2593 WQ > > > > setup: > > > > wq[35]-id=35 assoc=35, cq[35]-id=35 > > > > [ 151.617510] lpfc 0000:0b:00.0: 184: [ 148.763089] > > 2:(0):0356 > > > > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 > > x4 > > > > x4 > > > > x24 xb8000000 x24 x1000 CQ: x0 x0 x0 x90000000 > > > > [ 151.715751] lpfc 0000:0b:00.0: 185: [ 148.763090] 2:6087 CQ > > > > setup: > > > > cq[36]-id=36, parent eq[36]-id=36 > > > > [ 151.772034] lpfc 0000:0b:00.0: 186: [ 148.767155] > > 2:(0):0356 > > > > Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 > > x4 > > > > x4 > > > > x240024 x4008504 x0 xcf400000 CQ: x0 x0 x0 x90000000 > > > > [ 151.872722] lpfc 0000:0b:00.0: 187: [ 148.767156] 2:2593 WQ > > > > setup: > > > > wq[36]-id=36 assoc=36, cq[36]-id=36 > > > > [ 151.929396] lpfc 0000:0b:00.0: 188: [ 148.771220] > > 2:(0):0356 > > > > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 > > x4 > > > > x4 > > > > x25 xb8000000 x25 x1000 CQ: x0 x0 x0 x90000000 > > > > [ 152.030050] lpfc 0000:0b:00.0: 189: [ 148.771221] 2:6087 CQ > > > > setup: > > > > cq[37]-id=37, parent eq[37]-id=37 > > > > [ 152.085622] lpfc 0000:0b:00.0: 190: [ 148.775285] > > 2:(0):0356 > > > > Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 > > x4 > > > > x4 > > > > x250025 x4008504 x0 xbc7e0000 CQ: x0 x0 x0 x90000000 > > > > [ 152.185681] lpfc 0000:0b:00.0: 191: [ 148.775287] 2:2593 WQ > > > > setup: > > > > wq[37]-id=37 assoc=37, cq[37]-id=37 > > > > [ 152.243645] lpfc 0000:0b:00.0: 192: [ 148.779351] > > 2:(0):0356 > > > > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 > > x4 > > > > x4 > > > > x26 xb8000000 x26 x1000 CQ: x0 x0 x0 x90000000 > > > > [ 152.341442] lpfc 0000:0b:00.0: 193: [ 148.779352] 2:6087 CQ > > > > setup: > > > > cq[38]-id=38, parent eq[38]-id=38 > > > > [ 152.399734] lpfc 0000:0b:00.0: 194: [ 148.783416] > > 2:(0):0356 > > > > Mailbox cmd x9b (xc/x1) Status x0 Data: x1 x54 x0 x0 x0 xc01 x0 > > x4 > > > > x4 > > > > x260026 x4008504 x0 x5ef40000 CQ: x0 x0 x0 x90000000 > > > > [ 152.501390] lpfc 0000:0b:00.0: 195: [ 148.783417] 2:2593 WQ > > > > setup: > > > > wq[38]-id=38 assoc=38, cq[38]-id=38 > > > > [ 152.557531] lpfc 0000:0b:00.0: 196: [ 148.787481] > > 2:(0):0356 > > > > Mailbox cmd x9b (x1/xc) Status x0 Data: x1 x44 x0 x0 x0 x10c x0 > > x4 > > > > x4 > > > > x27 xb8000000 x27 x1000 CQ: x0 x0 x0 x90000000 > > > > .. > > > > .. > > > > [ 190.872503] lpfc 0000:0b:00.0: start 109 end 115 cnt 6 > > > > [ 190.872506] lpfc 0000:0b:00.0: 109: [ 190.871058] > > 2:(0):0117 > > > > Xmit > > > > ELS response x1 to remote NPORT x20300 I/O tag: xb92, size: x8 > > > > port_state x20 rpi x10 fc_flag x800110 > > > > [ 190.872507] lpfc 0000:0b:00.0: 110: [ 190.871060] > > 2:(0):0129 > > > > Xmit > > > > ELS RJT xb00 response tag xb92 xri xffff, did x20300, nlp_flag > > > > x80000000, nlp_state x7, rpi x10 > > > > [ 190.872509] lpfc 0000:0b:00.0: 111: [ 190.871085] > > 2:(0):0110 > > > > ELS > > > > response tag xb92 completes Data: x0 x0 x0 x20300 x80000000 x7 > > x10 > > > > [ 190.872511] lpfc 0000:0b:00.0: 112: [ 190.872497] 2:2538 > > > > Received > > > > frame rctl:x22, type:x1, frame Data:220a0300 00010600 01290000 > > > > 00000000 > > > > 0048ffff 00000000 00000000 > > > > [ 190.872512] lpfc 0000:0b:00.0: 113: [ 190.872500] > > 2:(0):0929 > > > > FIND > > > > node DID Data: xffff896e4faf2c00 x10600 x80000000 x7001801 xc > > > > xffff896e4faf1200 > > > > [ 190.872514] lpfc 0000:0b:00.0: 114: [ 190.872501] > > 2:(0):0112 > > > > ELS > > > > command x14001023 received from NPORT x10600 Data: x20 x800110 > > > > xa0300 > > > > xa0300 > > > > [ 190.872515] lpfc 0000:0b:00.0: 2:(0):0115 Unknown ELS > > command > > > > x14001023 received from NPORT x10600 > > > > [ 190.873239] lpfc 0000:0b:00.0: start 115 end 121 cnt 6 > > > > [ 190.873241] lpfc 0000:0b:00.0: 115: [ 190.872517] > > 2:(0):0117 > > > > Xmit > > > > ELS response x1 to remote NPORT x10600 I/O tag: xb8f, size: x8 > > > > port_state x20 rpi xc fc_flag x800110 > > > > [ 190.873243] lpfc 0000:0b:00.0: 116: [ 190.872519] > > 2:(0):0129 > > > > Xmit > > > > ELS RJT xb00 response tag xb8f xri xffff, did x10600, nlp_flag > > > > x80000000, nlp_state x7, rpi xc > > > > [ 190.873244] lpfc 0000:0b:00.0: 117: [ 190.872545] > > 2:(0):0110 > > > > ELS > > > > response tag xb8f completes Data: x0 x0 x0 x10600 x80000000 x7 > > xc > > > > [ 190.873246] lpfc 0000:0b:00.0: 118: [ 190.873234] 2:2538 > > > > Received > > > > frame rctl:x22, type:x1, frame Data:220a0300 00010700 01290000 > > > > 00000000 > > > > 008cffff 00000000 00000000 > > > > [ 190.873249] lpfc 0000:0b:00.0: 119: [ 190.873236] > > 2:(0):0929 > > > > FIND > > > > node DID Data: xffff896e4faf0600 x10700 x80000000 x7001801 xd > > > > xffff896e4faf3600 > > > > > > > > I have not investogated the masking changes yet, decided to > > first > > > > ask. > > > > > > > > Thanks > > > > Laurence > > > > > > Hi Dick I dont see this when booting 5.5, which was when I last > > > tested, > > > and before I start the long arduous code review and maybe bisect > > I > > > would rather have you look at it. > > > Can you look at this please and let me know. > > > Its not happeniong on latest RHEL8 but could happen if we take > > latest > > > code in. > > > > > > Regards > > > Laurence > > > > > > > Dick > > Seems to be all these changes like below. all chamhed to > > LOG_TRACE_EVENT > > > > - lpfc_printf_vlog(vport, KERN_ERR, LOG_INIT > > | > > LOG_VPORT, > > + lpfc_printf_vlog(vport, KERN_ERR, > > LOG_TRACE_EVENT, > > OK, Perfect, Thanks Dick Regards Laurence ^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2020-09-11 19:18 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-09-10 16:36 lpfc on latest 5.9 is very chatty on modprobe Laurence Oberman
2020-09-11 15:09 ` Laurence Oberman
2020-09-11 15:55 ` Laurence Oberman
[not found] ` <CAGx+d6dhGuJdUfisgvVfaTJ5aT7D9hP+WQcaD485iF=tuKqv7w@mail.gmail.com>
2020-09-11 19:18 ` Laurence Oberman
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).