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@xxxxxxxxxx> 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
