Vasu Dev wrote:
> On Thu, 2009-08-06 at 12:18 -0700, Vasu Dev wrote:
>> On Wed, 2009-08-05 at 18:22 -0700, Joe Eykholt wrote:
>>> Vasu Dev wrote:
>>>> On Wed, 2009-08-05 at 14:10 -0700, Joe Eykholt wrote:
>>>>> Hi All,
>>>>>
>>>>> I'm posting this problem description hoping someone sees the problem,
>>>>> or perhaps has run into it.
>>>>>
>>>>> Vasu, I'm hoping you'll take a look at this since you're so familiar with
>>>>> the exchange manager.
>>>>>
>>>>> I've been seeing an occasional problem where I'm trying to unload
>>>>> the libfc module, after all instances are destroyed and fcoe.ko and
>>>>> libfcoe
>>>>> have been removed, where one exchange is still not freed. If using the
>>>>> slab allocator, it results in a message from kmem_cache_destroy()
>>>>> "Can't free all objects".
>>>>>
>>>> This issue could be similar as reported by you in this RFC
>>>>
>>>> http://www.open-fcoe.org/pipermail/devel/2009-July/003401.html
>>>>
>>>> So is this issue even with your patch in above RFC ?
>>> Yes, even with that patch.
>>>
>>>> It could be similar as in above RFC since an exch must have got
>>>> allocated after final EM reset. I'll look more into these debug info and
>>>> get back to you.
>>> I'm not sure it's after the final reset. I can add debug code to
>>> make sure it isn't allocated after that final reset.
>>>
>>> One clue is the XID is 0, and I don't think that would
>>> happen except by huge coincidence
>>> after the lport has been up for a while. It must've been the first
>>> exchange that was created. It must've timed out but I don't see
>>> any bugs in that path. I can print the xids in my trace, that
>>> may also help.
>>>
>
> I reviewed flogi exch timeout and retry code paths. I also don't see any
> obvious issue in that code paths which could cause surplus ref on flogi
> exch.
>
> I also did > 100 times create, destroy and rmmod in loop with these
> additional settings.
>
> 1. Set flog exch timeout to small value (1 to 5ms) and drop
> initial 10 flogi reqs in fip els send. I did this test since your log
> had exch timeout on flogi exch as its state was 0x3.
>
> I see the abort handling has special case for pending flogi to not do
> actual abort processing but I don't see anyway that could lead to
> surplus flogi exch ref.
>
> 2. Added few sleep 0 to 3 sec sleep after create to let lun discovered.
>
> In this case flogi exch got extra exch ref while fc_exch reset has
> occurred, so my debug patch is not going to help in root causing how
> extra exch ref was taken. If I could reproduce this issue here then I
> could do some more investigation.
>
> Vasu
I also don't see it happening very often, it sometimes goes 300 create/deletes.
I have seen it on exchange IDs other than 0. Actually only 0 and 5 so far,
it takes a long time to happen.
I think it's more rare now that we have per-cpu pools, for some reason.
I ported your patch to my tree and am running with it.
I don't think we should have to wait for exchanges to be released.
Thanks for trying it out. I'll keep running and trying to provoke it again.
Joe
>>> I've refreshed to the latest patches and am testing it again.
>>>
>> Joe it would be great if you can repeat your test with my debug patch,
>> more details below on debug patch.
>>
>> I think following cases could lead to pending exch/es while destroying
>> EM mempool:-
>>
>> 1. exch being allocated after final EM reset as we talked before.
>> 2. currently i/f destroy code does't wait for all exches released to
>> mempool.
>>
>> I added code for above two cases in debug patch to help us in root
>> causing this issue.
>>
>> The debug patch adds code for case 1 to abandon exch alloc in case the
>> lport has entered into LPORT_ST_DISABLED state. I also added
>> dump_stack() for this case to help us track down source any such exch
>> allocation request while LPORT_ST_DISABLED.
>>
>> Added code for case 2 to wait for all pending exches released to mempool
>> before destroying EM mempool. You can combine this code change with your
>> code printing pending exch details just before waiting for all pending
>> exches released in fc_exch_mgr_destroy. I think we need this fix any way
>> since currently destroy i/f code path doesn't wait for all exch released
>> to mempool but not sure if we can have better fix than waiting on
>> completion as my debug patch does with added stat counter for this.
>>
>> I'm sending debug patch separately since I could not send attachment on
>> this mail list before.
>>
>> I'll also try reproducing this issue here to root cause this issue.
>>
>> Vasu
>>
>>
>>> Thanks for thinking about this.
>>>
>>> Joe
>>>
>>>
>>>> Vasu
>>>>
>>>>
>>>>> I added debug code to keep a list of all exchanges, even those that
>>>>> have been completed, until the last fc_exch_release() frees it.
>>>>>
>>>>> I hit this after creating and deleting 75 times, so it doesn't
>>>>> happen that often. After it does, though, you can't reload libfc anymore.
>>>>>
>>>>> In this case, it's an exchange for an outgoing FLOGI. Its refcnt is 1,
>>>>> and it
>>>>> happens to have XID of 0. I can't figure out any way that's special.
>>>>>
>>>>> Here's the exchange from kgdb:
>>>>>
>>>>>> $5 = {em = 0xffff88012c480000, state = 0x3, xid = 0x0, ex_list = {
>>>>>> next = 0x100100, prev = 0x200200}, ex_debug = {next =
>>>>>> 0xffff88012c480058,
>>>>>> prev = 0xffff88012c480058}, ex_lock = {raw_lock = {slock = 0x404},
>>>>>> magic = 0xdead4ead, owner_cpu = 0xffffffff, owner =
>>>>>> 0xffffffffffffffff,
>>>>>> dep_map = {key = 0xffffffffa05458d8, class_cache = 0x0,
>>>>>> name = 0xffffffffa053e72c}}, ex_refcnt = {counter = 0x1},
>>>>>> timeout_work = {work = {data = {counter = 0xffff88002809c601}, entry =
>>>>>> {
>>>>>> next = 0xffff88002809c630, prev = 0xffff8801325a3e00},
>>>>>> func = 0xffffffffa05361d2, lockdep_map = {key = 0xffffffffa05458d0,
>>>>>> class_cache = 0x0, name = 0xffffffffa053e739}}, timer = {entry =
>>>>>> {
>>>>>> next = 0x0, prev = 0x200200}, expires = 0x1001045aa,
>>>>>> function = 0xffffffff81053ba5, data = 0xffff88012c9276e8,
>>>>>> base = 0xffff88013faf0000, start_site = 0x0, start_comm = {
>>>>>> 0x0 <repeats 16 times>}, start_pid = 0xffffffff, lockdep_map = {
>>>>>> key = 0xffffffffa05458c8, class_cache = 0x0,
>>>>>> name = 0xffffffffa053e754}}}, lp = 0xffff88012c85c5d8, oxid =
>>>>>> 0x0,
>>>>>> rxid = 0xffff, oid = 0x0, sid = 0x0, did = 0xfffffe, esb_stat =
>>>>>> 0x70000000,
>>>>>> r_a_tov = 0x2710, seq_id = 0x2, f_ctl = 0x90000, fh_type = 0x1,
>>>>>> class = 0x2e, seq = {id = 0x1, ssb_stat = 0x0, cnt = 0x0, rec_data =
>>>>>> 0x0},
>>>>>> resp = 0x0, destructor = 0x0, arg = 0xffff88012c85c5d8}
>>>>> I looked at the work.data and work.timer. work.data shows work is
>>>>> pending,
>>>>> and work.timer shows the timer isn't pending. I thought maybe the
>>>>> timer_cancel_sync in fc_exch_reset could be at fault, but I don't think
>>>>> so now.
>>>>>
>>>>> This is with the previous rebase, before the per-cpu exchange pools,
>>>>> and with some additional rport/lport changes by me.
>>>>>
>>>>> Also, in case you're interested, here's the log with lport and rport debug
>>>>> messages (with a temporarily-modified rport debug format).
>>>>>
>>>>> host75 is the one that has the leaked exchange.
>>>>>
>>>>>
>>>>>
>>>>> [ 1344.349639] scsi74 : FCoE Driver
>>>>> [ 1344.353338] host74: lport ffffffff: Entered RESET state from disabled
>>>>> state
>>>>> [ 1344.360517] libfc: Link up on port ( 0)
>>>>> [ 1344.364840] host74: lport 0: Entered FLOGI state from reset state
>>>>> [ 1344.371523] device eth0 entered promiscuous mode
>>>>> [ 1344.376393] scsi75 : FCoE Driver
>>>>> [ 1344.380010] host75: lport ffffffff: Entered RESET state from disabled
>>>>> state
>>>>> [ 1344.387119] libfc: Link up on port ( 0)
>>>>> [ 1344.391422] host75: lport 0: Entered FLOGI state from reset state
>>>>> [ 1346.371007] libfcoe: host74: FIP selected Fibre-Channel Forwarder MAC
>>>>> 00:0d:ec:6d:b2:c0
>>>>> [ 1346.371010] host74: lport 0: Received a FLOGI response timeout
>>>>> [ 1346.371014] host74: lport 0: Error -1 in state FLOGI, retries 0
>>>>> [ 1346.398012] host75: lport 0: Received a FLOGI response timeout
>>>>> [ 1346.404404] host75: lport 0: Error -1 in state FLOGI, retries 0
>>>>> [ 1348.371008] host74: lport 0: Entered FLOGI state from FLOGI state
>>>>> [ 1348.402343] host74: lport 0: Received a FLOGI accept
>>>>> [ 1348.407863] libfc: Assigned FID (6a0000) in FLOGI response
>>>>> [ 1348.410011] host75: lport 0: Entered FLOGI state from FLOGI state
>>>>> [ 1348.420127] host74: lport 6a0000: Entered DNS state from FLOGI state
>>>>> [ 1348.426583] host74: rport fffffc: ffff88012c8cf000 r 1 Init Login
>>>>> to port
>>>>> [ 1348.433865] host74: rport fffffc: ffff88012c8cf000 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1348.443719] host74: rport fffffc: ffff88012c8cf000 r 2 PLOGI
>>>>> Received a PLOGI accept
>>>>> [ 1348.452141] host74: rport fffffc: ffff88012c8cf000 r 2 Ready Port
>>>>> is Ready
>>>>> [ 1348.459461] host74: rport fffffc: ffff88012c8cf000 r 1 Ready work
>>>>> event 1
>>>>> [ 1348.466964] host74: rport fffffc: ffff88012c8cf000 r 2 Ready
>>>>> callback ev 1
>>>>> [ 1348.474454] host74: lport 6a0000: Received a 1 event for port (fffffc)
>>>>> [ 1348.481110] host74: lport 6a0000: Entered RPN_ID state from dNS state
>>>>> [ 1348.487949] host74: lport 6a0000: Received a RPN_ID reject
>>>>> [ 1348.493590] host74: lport 6a0000: Entered RFT_ID state from RPN_ID
>>>>> state
>>>>> [ 1348.500838] host74: lport 6a0000: Received a RFT_ID reject
>>>>> [ 1348.506448] host74: lport 6a0000: Entered SCR state from RFT_ID state
>>>>> [ 1348.513341] host74: lport 6a0000: Received a SCR accept
>>>>> [ 1348.518679] host74: lport 6a0000: Entered READY from state SCR
>>>>> [ 1348.524641] host74: disc: Restarting discovery
>>>>> [ 1348.529793] host74: disc: Received a GPN_FT response
>>>>> [ 1348.534861] host74: disc: Discovery complete
>>>>> [ 1348.539205] host74: rport d10400: ffff88013d7d7800 r 1 Init Login
>>>>> to port
>>>>> [ 1348.546485] host74: rport d10400: ffff88013d7d7800 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1348.556188] host74: rport 35000f: ffff88013d7d7a00 r 1 Init Login
>>>>> to port
>>>>> [ 1348.562418] host74: rport d10400: ffff88013d7d7800 r 2 PLOGI
>>>>> Received a PLOGI accept
>>>>> [ 1348.562421] host74: rport d10400: ffff88013d7d7800 r 2 PLOGI Port
>>>>> entered PRLI state from PLOGI state
>>>>> [ 1348.569143] host74: rport d10400: ffff88013d7d7800 r 2 PRLI
>>>>> Received a PRLI accept
>>>>> [ 1348.569147] host74: rport d10400: ffff88013d7d7800 r 2 PRLI Port
>>>>> entered RTV state from PRLI state
>>>>> [ 1348.569461] host74: rport d10400: ffff88013d7d7800 r 2 RTV
>>>>> Received a RTV reject
>>>>> [ 1348.569464] host74: rport d10400: ffff88013d7d7800 r 2 Ready Port
>>>>> is Ready
>>>>> [ 1348.569475] host74: rport d10400: ffff88013d7d7800 r 1 Ready work
>>>>> event 1
>>>>> [ 1348.621266] host74: rport 35000f: ffff88013d7d7a00 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1348.630942] host74: rport 706e1: ffff88013d7d7000 r 1 Init Login
>>>>> to port
>>>>> [ 1348.638207] host74: rport 706e1: ffff88013d7d7000 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1348.647882] host74: rport 700e1: ffff88012c8cf200 r 1 Init Login
>>>>> to port
>>>>> [ 1348.654244] host74: rport 706e1: ffff88013d7d7000 r 2 PLOGI
>>>>> Received a PLOGI accept
>>>>> [ 1348.654247] host74: rport 706e1: ffff88013d7d7000 r 2 PLOGI Port
>>>>> entered PRLI state from PLOGI state
>>>>> [ 1348.660184] host74: rport 706e1: ffff88013d7d7000 r 2 PRLI
>>>>> Received a PRLI accept
>>>>> [ 1348.660187] host74: rport 706e1: ffff88013d7d7000 r 2 PRLI Port
>>>>> entered RTV state from PRLI state
>>>>> [ 1348.690498] host74: rport 700e1: ffff88012c8cf200 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1348.700188] host74: lport 6a0000: Discovery succeeded
>>>>> [ 1348.705366] host74: rport 706e1: ffff88013d7d7000 r 2 RTV
>>>>> Received a RTV reject
>>>>> [ 1348.706162] host74: rport 700e1: ffff88012c8cf200 r 2 PLOGI
>>>>> Received a PLOGI accept
>>>>> [ 1348.706164] host74: rport 700e1: ffff88012c8cf200 r 2 PLOGI Port
>>>>> entered PRLI state from PLOGI state
>>>>> [ 1348.707576] scsi 74:0:0:0: Sequential-Access IBM ULTRIUM-TD3
>>>>> 54K1 PQ: 0 ANSI: 3
>>>>> [ 1348.707903] st 74:0:0:0: Attached scsi tape st0
>>>>> [ 1348.707904] st 74:0:0:0: st0: try direct i/o: yes (alignment 4 B)
>>>>> [ 1348.707959] st 74:0:0:0: Attached scsi generic sg2 type 1
>>>>> [ 1348.714198] scsi 74:0:0:1: Medium Changer ADIC Scalar 24
>>>>> 309A PQ: 0 ANSI: 2
>>>>> [ 1348.714337] scsi 74:0:0:1: Attached scsi generic sg3 type 8
>>>>> [ 1348.770027] host74: rport 706e1: ffff88013d7d7000 r 2 Ready Port
>>>>> is Ready
>>>>> [ 1348.777311] host74: rport 706e1: ffff88013d7d7000 r 1 Ready work
>>>>> event 1
>>>>> [ 1348.777313] host74: rport 700e1: ffff88012c8cf200 r 2 PRLI
>>>>> Received a PRLI accept
>>>>> [ 1348.777316] host74: rport 700e1: ffff88012c8cf200 r 2 PRLI Port
>>>>> entered RTV state from PRLI state
>>>>> [ 1348.802811] host74: rport 700e1: ffff88012c8cf200 r 2 RTV
>>>>> Received a RTV reject
>>>>> [ 1348.811063] host74: rport 700e1: ffff88012c8cf200 r 2 Ready Port
>>>>> is Ready
>>>>> [ 1348.824261] host74: rport 700e1: ffff88012c8cf200 r 1 Ready work
>>>>> event 1
>>>>> [ 1348.825187] scsi 74:0:1:0: Direct-Access SEAGATE ST318453FC
>>>>> 0003 PQ: 0 ANSI: 3
>>>>> [ 1348.825356] sd 74:0:1:0: Attached scsi generic sg4 type 0
>>>>> [ 1348.847364] sd 74:0:1:0: [sdb] 35843686 512-byte logical blocks: (18.3
>>>>> GB/17.0 GiB)
>>>>> [ 1348.856727] sd 74:0:1:0: [sdb] Write Protect is off
>>>>> [ 1348.861742] sd 74:0:1:0: [sdb] Mode Sense: ab 00 10 08
>>>>> [ 1348.867036] scsi 74:0:2:0: Direct-Access SEAGATE ST118202FC
>>>>> 0008 PQ: 0 ANSI: 2
>>>>> [ 1348.867953] sd 74:0:1:0: [sdb] Write cache: disabled, read cache:
>>>>> enabled, supports DPO and FUA
>>>>> [ 1348.872317] __ratelimit: 122 callbacks suppressed
>>>>> [ 1348.872320] <6>nm-system-setti[22981]: segfault at 0 ip
>>>>> 00000000004082d9 sp 00007fffdcaa98a0 error 4 in
>>>>> nm-system-settings[400000+f000]
>>>>> [ 1348.901961] sd 74:0:2:0: Attached scsi generic sg5 type 0
>>>>> [ 1348.907533] sdb:
>>>>> [ 1348.909365] sd 74:0:2:0: [sdc] 35566480 512-byte logical blocks: (18.2
>>>>> GB/16.9 GiB)
>>>>> [ 1348.917592] sdb1 sdb2 sdb3 <
>>>>> [ 1348.923018] sd 74:0:2:0: [sdc] Write Protect is off
>>>>> [ 1348.928192] sd 74:0:2:0: [sdc] Mode Sense: a7 00 10 08
>>>>> [ 1348.933458] sdb5 >
>>>>> [ 1348.936513] sd 74:0:2:0: [sdc] Write cache: disabled, read cache:
>>>>> enabled, supports DPO and FUA
>>>>> [ 1348.951088] sdc:
>>>>> [ 1348.954758] sd 74:0:1:0: [sdb] Attached SCSI disk
>>>>> [ 1348.960195] unknown partition table
>>>>> [ 1348.972201] sd 74:0:2:0: [sdc] Attached SCSI disk
>>>>> [ 1350.410009] host75: lport 0: Received a FLOGI response timeout
>>>>> [ 1350.416404] host75: lport 0: Error -1 in state FLOGI, retries 1
>>>>> [ 1350.630010] host74: rport 35000f: ffff88013d7d7a00 r 2 PLOGI
>>>>> Received a PLOGI response timeout
>>>>> [ 1350.639338] host74: rport 35000f: ffff88013d7d7a00 r 2 PLOGI Error
>>>>> -1 in state PLOGI, retrying
>>>>> [ 1350.648402] host74: rport 35000f: ffff88013d7d7a00 r 1 PLOGI Port
>>>>> entered PLOGI state from PLOGI state
>>>>> [ 1352.422011] host75: lport 0: Entered FLOGI state from FLOGI state
>>>>> [ 1352.446174] host75: lport 0: Received a FLOGI accept
>>>>> [ 1352.451688] libfc: Assigned FID ( 70500) in FLOGI response
>>>>> [ 1352.457286] host75: lport 70500: Entered DNS state from FLOGI state
>>>>> [ 1352.463778] host75: rport fffffc: ffff880132542200 r 1 Init Login
>>>>> to port
>>>>> [ 1352.471048] host75: rport fffffc: ffff880132542200 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1352.481675] host75: rport fffffc: ffff880132542200 r 2 PLOGI
>>>>> Received a PLOGI accept
>>>>> [ 1352.490089] host75: rport fffffc: ffff880132542200 r 2 Ready Port
>>>>> is Ready
>>>>> [ 1352.497371] host75: rport fffffc: ffff880132542200 r 1 Ready work
>>>>> event 1
>>>>> [ 1352.504920] host75: rport fffffc: ffff880132542200 r 2 Ready
>>>>> callback ev 1
>>>>> [ 1352.512421] host75: lport 70500: Received a 1 event for port (fffffc)
>>>>> [ 1352.519075] host75: lport 70500: Entered RPN_ID state from dNS state
>>>>> [ 1352.526679] host75: lport 70500: Received a RPN_ID reject
>>>>> [ 1352.532316] host75: lport 70500: Entered RFT_ID state from RPN_ID
>>>>> state
>>>>> [ 1352.540561] host75: lport 70500: Received a RFT_ID reject
>>>>> [ 1352.546164] host75: lport 70500: Entered SCR state from RFT_ID state
>>>>> [ 1352.553938] host75: lport 70500: Received a SCR accept
>>>>> [ 1352.559269] host75: lport 70500: Entered READY from state SCR
>>>>> [ 1352.565413] host75: disc: Restarting discovery
>>>>> [ 1352.571972] host75: disc: Received a GPN_FT response
>>>>> [ 1352.577025] host75: disc: Discovery complete
>>>>> [ 1352.581389] host75: rport 6a0000: ffff8801399a8600 r 1 Init Login
>>>>> to port
>>>>> [ 1352.588650] host75: rport 6a0000: ffff8801399a8600 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1352.598319] host75: rport 706e1: ffff8801399a8400 r 1 Init Login
>>>>> to port
>>>>> [ 1352.605600] host75: rport 706e1: ffff8801399a8400 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1352.605607] host75: rport 6a0000: ffff8801399a8600 r 2 PLOGI
>>>>> Received a PLOGI reject
>>>>> [ 1352.605610] host75: rport 6a0000: ffff8801399a8600 r 2 PLOGI Error
>>>>> -131936256018240 in state PLOGI, retrying
>>>>> [ 1352.633938] host75: rport 700e1: ffff880132542e00 r 1 Init Login
>>>>> to port
>>>>> [ 1352.641222] host75: rport 700e1: ffff880132542e00 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1352.650884] host75: rport 706e1: ffff8801399a8400 r 2 PLOGI
>>>>> Received a PLOGI accept
>>>>> [ 1352.650886] host75: lport 70500: Discovery succeeded
>>>>> [ 1352.658009] host74: rport 35000f: ffff88013d7d7a00 r 2 PLOGI
>>>>> Received a PLOGI response timeout
>>>>> [ 1352.658012] host74: rport 35000f: ffff88013d7d7a00 r 2 PLOGI Error
>>>>> -1 in state PLOGI, retrying
>>>>> [ 1352.658019] host74: rport 35000f: ffff88013d7d7a00 r 1 PLOGI Port
>>>>> entered PLOGI state from PLOGI state
>>>>> [ 1352.662658] host75: rport 700e1: ffff880132542e00 r 2 PLOGI
>>>>> Received a PLOGI accept
>>>>> [ 1352.662660] host75: rport 700e1: ffff880132542e00 r 2 PLOGI Port
>>>>> entered PRLI state from PLOGI state
>>>>> [ 1352.668572] host75: rport 700e1: ffff880132542e00 r 2 PRLI
>>>>> Received a PRLI accept
>>>>> [ 1352.668575] host75: rport 700e1: ffff880132542e00 r 2 PRLI Port
>>>>> entered RTV state from PRLI state
>>>>> [ 1352.668877] host75: rport 700e1: ffff880132542e00 r 2 RTV
>>>>> Received a RTV reject
>>>>> [ 1352.668880] host75: rport 700e1: ffff880132542e00 r 2 Ready Port
>>>>> is Ready
>>>>> [ 1352.668886] host75: rport 700e1: ffff880132542e00 r 1 Ready work
>>>>> event 1
>>>>> [ 1352.749757] host75: rport 706e1: ffff8801399a8400 r 2 PLOGI Port
>>>>> entered PRLI state from PLOGI state
>>>>> [ 1352.763304] scsi 75:0:0:0: Direct-Access SEAGATE ST118202FC
>>>>> 0008 PQ: 0 ANSI: 2
>>>>> [ 1352.771668] host75: rport 706e1: ffff8801399a8400 r 2 PRLI
>>>>> Received a PRLI accept
>>>>> [ 1352.779740] host75: rport 706e1: ffff8801399a8400 r 2 PRLI Port
>>>>> entered RTV state from PRLI state
>>>>> [ 1352.789466] sd 75:0:0:0: Attached scsi generic sg6 type 0
>>>>> [ 1352.789496] host75: rport 706e1: ffff8801399a8400 r 2 RTV
>>>>> Received a RTV reject
>>>>> [ 1352.789498] host75: rport 706e1: ffff8801399a8400 r 2 Ready Port
>>>>> is Ready
>>>>> [ 1352.789505] host75: rport 706e1: ffff8801399a8400 r 1 Ready work
>>>>> event 1
>>>>> [ 1352.818557] sd 75:0:0:0: [sdd] 35566480 512-byte logical blocks: (18.2
>>>>> GB/16.9 GiB)
>>>>> [ 1352.828779] scsi 75:0:1:0: Direct-Access SEAGATE ST318453FC
>>>>> 0003 PQ: 0 ANSI: 3
>>>>> [ 1352.829902] sd 75:0:0:0: [sdd] Write Protect is off
>>>>> [ 1352.829904] sd 75:0:0:0: [sdd] Mode Sense: a7 00 10 08
>>>>> [ 1352.847625] sd 75:0:1:0: Attached scsi generic sg7 type 0
>>>>> [ 1352.848384] sd 75:0:0:0: [sdd] Write cache: disabled, read cache:
>>>>> enabled, supports DPO and FUA
>>>>> [ 1352.862947] sd 75:0:1:0: [sde] 35843686 512-byte logical blocks: (18.3
>>>>> GB/17.0 GiB)
>>>>> [ 1352.872587] sd 75:0:1:0: [sde] Write Protect is off
>>>>> [ 1352.877567] sd 75:0:1:0: [sde] Mode Sense: ab 00 10 08
>>>>> [ 1352.882857] sdd:
>>>>> [ 1352.885871] sd 75:0:1:0: [sde] Write cache: disabled, read cache:
>>>>> enabled, supports DPO and FUA
>>>>> [ 1352.895690] unknown partition table
>>>>> [ 1352.902474] sde:
>>>>> [ 1352.909401] sd 75:0:0:0: [sdd] Attached SCSI disk
>>>>> [ 1352.914403] sde1 sde2 sde3 < sde5 >
>>>>> [ 1352.965207] sd 75:0:1:0: [sde] Attached SCSI disk
>>>>> [ 1354.464657] host74: disc: Received an RSCN event
>>>>> [ 1354.469392] host74: disc: Port address format for port ( 70500)
>>>>> [ 1354.475432] host74: disc: RSCN received: not rediscovering. redisc 0
>>>>> state 6 in_prog 0
>>>>> [ 1354.483521] host74: rport 70500: ffff88013243a000 r 1 Init Login
>>>>> to port
>>>>> [ 1354.490805] host74: rport 70500: ffff88013243a000 r 1 Init Port
>>>>> entered PLOGI state from Init state
>>>>> [ 1354.500602] host75: rport 6a0000: ffff8801399a8600 r 1 PLOGI
>>>>> Received PLOGI request while in state PLOGI
>>>>> [ 1354.510544] host75: rport 6a0000: ffff8801399a8600 r 1 PLOGI
>>>>> Received PLOGI in PLOGI state 1
>>>>> [ 1354.519419] host75: rport 6a0000: ffff8801399a8600 r 1 PLOGI Port
>>>>> entered PRLI state from PLOGI state
>>>>> [ 1354.529109] host74: rport 70500: ffff88013243a000 r 2 PLOGI
>>>>> Received a PLOGI accept
>>>>> [ 1354.537282] host74: rport 70500: ffff88013243a000 r 2 PLOGI Port
>>>>> entered PRLI state from PLOGI state
>>>>> [ 1354.546956] host74: rport 70500: ffff88013243a000 r 2 PRLI
>>>>> Received PRLI request while in state PRLI
>>>>> [ 1354.547035] host75: rport 6a0000: ffff8801399a8600 r 2 PRLI
>>>>> Received PRLI request while in state PRLI
>>>>> [ 1354.547043] host75: rport 6a0000: ffff8801399a8600 r 2 Ready Port
>>>>> is Ready
>>>>> [ 1354.547053] host75: rport 6a0000: ffff8801399a8600 r 2 Ready work
>>>>> event 1
>>>>> [ 1354.581028] host74: rport 70500: ffff88013243a000 r 2 Ready Port
>>>>> is Ready
>>>>> [ 1354.588300] host74: rport 70500: ffff88013243a000 r 2 Ready work
>>>>> event 1
>>>>> [ 1354.588304] host75: rport 6a0000: ffff8801399a8600 r 2 Ready
>>>>> Received a PRLI accept
>>>>> [ 1354.588306] host75: rport 6a0000: ffff8801399a8600 r 2 Ready
>>>>> Received a PRLI response, but in state Ready
>>>>> [ 1354.614370] host74: rport 70500: ffff88013243a000 r 3 Ready
>>>>> Received a PRLI accept
>>>>> [ 1354.622545] host74: rport 70500: ffff88013243a000 r 3 Ready
>>>>> Received a PRLI response, but in state Ready
>>>>> [ 1354.659016] host74: rport 35000f: ffff88013d7d7a00 r 2 PLOGI
>>>>> Received a PLOGI response timeout
>>>>> [ 1354.668340] host74: rport 35000f: ffff88013d7d7a00 r 2 PLOGI Error
>>>>> -1 in state PLOGI, retrying
>>>>> [ 1354.677750] host74: rport 35000f: ffff88013d7d7a00 r 1 PLOGI Port
>>>>> entered PLOGI state from PLOGI state
>>>>> [ 1356.687018] host74: rport 35000f: ffff88013d7d7a00 r 2 PLOGI
>>>>> Received a PLOGI response timeout
>>>>> [ 1356.696363] host74: rport 35000f: ffff88013d7d7a00 r 2 PLOGI Error
>>>>> 1 in state PLOGI, retries 3
>>>>> [ 1356.705440] host74: rport 35000f: ffff88013d7d7a00 r 2 PLOGI Delete
>>>>> port
>>>>> [ 1356.712547] host74: rport 35000f: ffff88013d7d7a00 r 1 Delete work
>>>>> event 2
>>>>> [ 1366.114651] host74: rport 70500: ffff88013243a000 r 1 Ready Remove
>>>>> port
>>>>> [ 1366.121756] host74: rport 70500: ffff88013243a000 r 1 Ready Port
>>>>> entered LOGO state from Ready state
>>>>> [ 1366.131431] host74: rport 70500: ffff88013243a000 r 2 LOGO Delete
>>>>> port
>>>>> [ 1366.138548] host74: rport 70500: ffff88013243a000 r 2 Delete work
>>>>> event 3
>>>>> [ 1366.145976] host74: rport d10400: ffff88013d7d7800 r 1 Ready Remove
>>>>> port
>>>>> [ 1366.153060] host74: rport d10400: ffff88013d7d7800 r 1 Ready Port
>>>>> entered LOGO state from Ready state
>>>>> [ 1366.162751] host74: rport d10400: ffff88013d7d7800 r 2 LOGO Delete
>>>>> port
>>>>> [ 1366.169862] host74: rport 706e1: ffff88013d7d7000 r 1 Ready Remove
>>>>> port
>>>>> [ 1366.176959] host74: rport 706e1: ffff88013d7d7000 r 1 Ready Port
>>>>> entered LOGO state from Ready state
>>>>> [ 1366.186633] host74: rport 706e1: ffff88013d7d7000 r 2 LOGO Delete
>>>>> port
>>>>> [ 1366.193738] host74: rport 700e1: ffff88012c8cf200 r 1 Ready Remove
>>>>> port
>>>>> [ 1366.200860] host74: rport 700e1: ffff88012c8cf200 r 1 Ready Port
>>>>> entered LOGO state from Ready state
>>>>> [ 1366.210543] host74: rport 700e1: ffff88012c8cf200 r 2 LOGO Delete
>>>>> port
>>>>> [ 1366.217668] host74: rport 70500: ffff88013243a000 r 2 Delete
>>>>> Received a LOGO response closed
>>>>> [ 1366.226530] host74: rport 70500: ffff88013243a000 r 2 Delete
>>>>> Received a LOGO response, but in state Delete
>>>>> [ 1366.236649] host74: rport d10400: ffff88013d7d7800 r 2 Delete work
>>>>> event 3
>>>>> [ 1366.244064] host74: rport d10400: ffff88013d7d7800 r 2 Delete
>>>>> Received a LOGO response closed
>>>>> [ 1366.252935] host74: rport d10400: ffff88013d7d7800 r 2 Delete
>>>>> Received a LOGO response, but in state Delete
>>>>> [ 1366.263074] host74: rport 706e1: ffff88013d7d7000 r 2 Delete work
>>>>> event 3
>>>>> [ 1366.270279] host74: rport 706e1: ffff88013d7d7000 r 2 Delete
>>>>> Received a LOGO response closed
>>>>> [ 1366.279149] host74: rport 706e1: ffff88013d7d7000 r 2 Delete
>>>>> Received a LOGO response, but in state Delete
>>>>> [ 1366.289276] host74: rport 700e1: ffff88012c8cf200 r 2 Delete work
>>>>> event 3
>>>>> [ 1366.296465] host74: rport 700e1: ffff88012c8cf200 r 2 Delete
>>>>> Received a LOGO response closed
>>>>> [ 1366.305355] host74: rport 700e1: ffff88012c8cf200 r 2 Delete
>>>>> Received a LOGO response, but in state Delete
>>>>> [ 1366.315481] host74: rport fffffc: ffff88012c8cf000 r 1 Ready Remove
>>>>> port
>>>>> [ 1366.322592] host74: rport fffffc: ffff88012c8cf000 r 1 Ready Port
>>>>> entered LOGO state from Ready state
>>>>> [ 1366.332259] host74: rport fffffc: ffff88012c8cf000 r 2 LOGO Delete
>>>>> port
>>>>> [ 1366.339376] host74: rport fffffc: ffff88012c8cf000 r 2 Delete work
>>>>> event 3
>>>>> [ 1366.346561] host74: rport fffffc: ffff88012c8cf000 r 2 Delete
>>>>> callback ev 3
>>>>> [ 1366.353824] host74: lport 6a0000: Received a 3 event for port (fffffc)
>>>>> [ 1366.360473] host74: rport fffffc: ffff88012c8cf000 r 2 Delete
>>>>> Received a LOGO response closed
>>>>> [ 1366.369345] host74: rport fffffc: ffff88012c8cf000 r 2 Delete
>>>>> Received a LOGO response, but in state Delete
>>>>> [ 1366.379441] host74: lport 6a0000: Entered LOGO state from Ready state
>>>>> [ 1366.386010] host74: lport 6a0000: Received a LOGO response closed
>>>>> [ 1366.398840] host75: rport 6a0000: ffff8801399a8600 r 1 Ready Remove
>>>>> port
>>>>> [ 1366.406020] host75: rport 6a0000: ffff8801399a8600 r 1 Ready Port
>>>>> entered LOGO state from Ready state
>>>>> [ 1366.415767] host75: rport 6a0000: ffff8801399a8600 r 2 LOGO Delete
>>>>> port
>>>>> [ 1366.422955] host75: rport 706e1: ffff8801399a8400 r 1 Ready Remove
>>>>> port
>>>>> [ 1366.422959] host75: rport 6a0000: ffff8801399a8600 r 2 Delete work
>>>>> event 3
>>>>> [ 1366.437221] host75: rport 706e1: ffff8801399a8400 r 1 Ready Port
>>>>> entered LOGO state from Ready state
>>>>> [ 1366.446910] host75: rport 706e1: ffff8801399a8400 r 2 LOGO Delete
>>>>> port
>>>>> [ 1366.454025] host75: rport 700e1: ffff880132542e00 r 1 Ready Remove
>>>>> port
>>>>> [ 1366.461138] host75: rport 700e1: ffff880132542e00 r 1 Ready Port
>>>>> entered LOGO state from Ready state
>>>>> [ 1366.470815] host75: rport 700e1: ffff880132542e00 r 2 LOGO Delete
>>>>> port
>>>>> [ 1366.477900] host75: rport 6a0000: ffff8801399a8600 r 2 Delete
>>>>> Received a LOGO response closed
>>>>> [ 1366.486811] host75: rport 6a0000: ffff8801399a8600 r 2 Delete
>>>>> Received a LOGO response, but in state Delete
>>>>> [ 1366.497074] host75: rport 706e1: ffff8801399a8400 r 2 Delete work
>>>>> event 3
>>>>> [ 1366.504264] host75: rport 706e1: ffff8801399a8400 r 2 Delete
>>>>> Received a LOGO response closed
>>>>> [ 1366.513153] host75: rport 706e1: ffff8801399a8400 r 2 Delete
>>>>> Received a LOGO response, but in state Delete
>>>>> [ 1366.523283] host75: rport 700e1: ffff880132542e00 r 2 Delete work
>>>>> event 3
>>>>> [ 1366.530471] host75: rport 700e1: ffff880132542e00 r 2 Delete
>>>>> Received a LOGO response closed
>>>>> [ 1366.539339] host75: rport 700e1: ffff880132542e00 r 2 Delete
>>>>> Received a LOGO response, but in state Delete
>>>>> [ 1366.549453] host75: rport fffffc: ffff880132542200 r 1 Ready Remove
>>>>> port
>>>>> [ 1366.556544] host75: rport fffffc: ffff880132542200 r 1 Ready Port
>>>>> entered LOGO state from Ready state
>>>>> [ 1366.566245] host75: rport fffffc: ffff880132542200 r 2 LOGO Delete
>>>>> port
>>>>> [ 1366.573343] host75: rport fffffc: ffff880132542200 r 2 Delete work
>>>>> event 3
>>>>> [ 1366.580538] host75: rport fffffc: ffff880132542200 r 2 Delete
>>>>> callback ev 3
>>>>> [ 1366.587820] host75: lport 70500: Received a 3 event for port (fffffc)
>>>>> [ 1366.594485] host75: rport fffffc: ffff880132542200 r 2 Delete
>>>>> Received a LOGO response closed
>>>>> [ 1366.603363] host75: rport fffffc: ffff880132542200 r 2 Delete
>>>>> Received a LOGO response, but in state Delete
>>>>> [ 1366.613488] host75: lport 70500: Entered LOGO state from Ready state
>>>>> [ 1366.620070] host75: lport 70500: Received a LOGO response closed
>>>>> [ 1366.630261] device eth0 left promiscuous mode
>>>>> [ 1366.636641] KGDB: Waiting for remote debugger
>>>>>
>>>>> KGDB was entered because of debug code I added showing one exchange still
>>>>> exists
>>>>> when fc_exch_mgr_destroy is called for host75.
>>>>>
>>>>> Thanks for your time on this.
>>>>>
>>>>> Joe
>>>>>
>>>>> _______________________________________________
>>>>> devel mailing list
>>>>> [email protected]
>>>>> http://www.open-fcoe.org/mailman/listinfo/devel
>>>> _______________________________________________
>>>> devel mailing list
>>>> [email protected]
>>>> http://www.open-fcoe.org/mailman/listinfo/devel
>> _______________________________________________
>> devel mailing list
>> [email protected]
>> http://www.open-fcoe.org/mailman/listinfo/devel
>
_______________________________________________
devel mailing list
[email protected]
http://www.open-fcoe.org/mailman/listinfo/devel
