Menu
▾
▴
Re: [PacketFence-users] auth request from wrong switch
|
From: Sokolowski, D. <DS...@ea...> - 2017-11-17 21:27:18
|
Hi again,
Thanks for your help.
The switches are not stacked but in a ring uplinked by 10Gb fiber. The switch with the high number ports is a 5 blade chassis, with switching blades in slots 1,2,5,6,7. Slots 3,4 are controller and standby controller. This is the switch we've been talking about so far.
It is not always the same switch, and not always the same ports. Some ports will be fine for days, and then begin to fail.
The majority of connections are in the chassis switch right now as we slowly move people over.
I'm not sure if this is a valid test, or what you were looking for. A machine that had a problem this morning got moved back to a legacy switch. The uplink to the legacy switch is gi1/1. The mac of the machine is 1866.da02.7879.
So before I moved the connection, the address-table shows it on gig1/1, (attachment "before-move.txt"), the uplink port, as expected.
After I move it to the packetfence controlled cisco chassis port gi7/46, in "sh mac address-table" it still shows up on gig1/1, and fails auth on it's port. (attachment "after-move.txt" and radius-debug-switch-log.txt).
Debug shows it trying to auth on port 5/1.
Show mac address-table shows it still on 1/1 (attachment after-move.txt) and packetfence shows it on 5/1.
[cid:image001.png@01D35FBB.EF955260]
After some time, maybe 30 min, the mac no longer shows in mac table, I unplugged and replugged nic, and I see:
And the mac is no longer listed in the address-table (attachment after-replug.txt).
2017-11-17 15:27:55,Local5.Debug,172.16.0.200,584764: 583835: Nov 17 20:27:55.777: dot1x-ev:[Gi7/46] Interface state changed to DOWN
2017-11-17 15:27:55,Local5.Debug,172.16.0.200,584765: 583836: Nov 17 20:27:55.777: dot1x-ev:[Gi7/46] Clearing all supplicant instances
2017-11-17 15:27:55,Local5.Notice,172.16.0.200,"584766: 583837: Nov 17 20:27:56.777: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet7/46, changed state to down"
2017-11-17 15:27:57,Local5.Error,172.16.0.200,"584767: 583838: Nov 17 20:27:57.777: %LINK-3-UPDOWN: Interface GigabitEthernet7/46, changed state to down"
2017-11-17 15:27:58,Local5.Warning,172.16.0.200,"584768: 583839: 000132: Nov 17 20:27:58.972: %PM-4-PORT_INCONSISTENT: STANDBY:Port Gi7/46 is inconsistent: IDB state down (set 00:00:03 ago),"
2017-11-17 15:27:59,Local5.Debug,172.16.0.200,"584769: link: up (3d06h ago), admin: up (10w2d ago)."
2017-11-17 15:28:15,Local5.Debug,172.16.0.200,584770: 583840: Nov 17 20:28:15.821: dot1x-ev:[Gi7/46] Interface state changed to UP
2017-11-17 15:28:16,Local5.Warning,172.16.0.200,"584771: 583841: 000133: Nov 17 20:28:15.976: %PM-4-PORT_CONSISTENT: STANDBY:Port Gi7/46 consistency has been restored, IDB state: up."
2017-11-17 15:28:17,Local5.Error,172.16.0.200,"584772: 583842: Nov 17 20:28:17.817: %LINK-3-UPDOWN: Interface GigabitEthernet7/46, changed state to up"
2017-11-17 15:28:17,Local5.Notice,172.16.0.200,"584773: 583843: Nov 17 20:28:18.817: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet7/46, changed state to up"
2017-11-17 15:28:19,Local5.Debug,172.16.0.200,"584774: 583844: Nov 17 20:28:20.633: dot1x-packet:[1866.da02.7879, Gi7/46] queuing an EAPOL pkt on Auth Q"
2017-11-17 15:28:19,Local5.Debug,172.16.0.200,584775: 583845: Nov 17 20:28:20.633: dot1x-packet:EAPOL pak rx - Ver: 0x1 type: 0x1
2017-11-17 15:28:19,Local5.Debug,172.16.0.200,584776: 583846: Nov 17 20:28:20.633: dot1x-packet: length: 0x0000
2017-11-17 15:28:19,Local5.Debug,172.16.0.200,"584777: 583847: Nov 17 20:28:20.633: dot1x-ev:[Gi7/46] Dequeued pkt: Int Gi7/46 CODE= 0,TYPE= 0,LEN= 0"
2017-11-17 15:28:19,Local5.Debug,172.16.0.200,"584778: 583848: Nov 17 20:28:20.633: dot1x-ev:[Gi7/46] Received pkt saddr =1866.da02.7879 , daddr = 0180.c200.0003, pae-ether-type = 888e.0101.0000"
2017-11-17 15:28:19,Local5.Debug,172.16.0.200,584779: 583849: Nov 17 20:28:20.633: dot1x-ev:[Gi7/46] Couldn't find the supplicant in the list
2017-11-17 15:28:20,Local5.Debug,172.16.0.200,"584780: 583850: Nov 17 20:28:20.633: dot1x-ev:[1866.da02.7879, Gi7/46] New client detected, sending session start event for 1866.da02.7879"
2017-11-17 15:28:20,Local5.Debug,172.16.0.200,584781: 583851: Nov 17 20:28:20.633: dot1x-ev:Start response callback failed for handle 0x00000000 and client 0x00000000
2017-11-17 15:28:24,Local5.Debug,172.16.0.200,"584782: 583852: Nov 17 20:28:25.633: dot1x-packet:[1866.da02.7879, Gi7/46] queuing an EAPOL pkt on Auth Q"
2017-11-17 15:28:24,Local5.Debug,172.16.0.200,584783: 583853: Nov 17 20:28:25.633: dot1x-packet:EAPOL pak rx - Ver: 0x1 type: 0x1
2017-11-17 15:28:24,Local5.Debug,172.16.0.200,584784: 583854: Nov 17 20:28:25.633: dot1x-packet: length: 0x0000
2017-11-17 15:28:24,Local5.Debug,172.16.0.200,"584785: 583855: Nov 17 20:28:25.633: dot1x-ev:[Gi7/46] Dequeued pkt: Int Gi7/46 CODE= 0,TYPE= 0,LEN= 0"
2017-11-17 15:28:24,Local5.Debug,172.16.0.200,"584786: 583856: Nov 17 20:28:25.633: dot1x-ev:[Gi7/46] Received pkt saddr =1866.da02.7879 , daddr = 0180.c200.0003, pae-ether-type = 888e.0101.0000"
2017-11-17 15:28:24,Local5.Debug,172.16.0.200,584787: 583857: Nov 17 20:28:25.633: dot1x-ev:[Gi7/46] Couldn't find the supplicant in the list
2017-11-17 15:28:25,Local5.Debug,172.16.0.200,"584788: 583858: Nov 17 20:28:25.633: dot1x-ev:[1866.da02.7879, Gi7/46] New client detected, sending session start event for 1866.da02.7879"
2017-11-17 15:28:25,Local5.Debug,172.16.0.200,584789: 583859: Nov 17 20:28:25.633: dot1x-ev:Start response callback failed for handle 0x00000000 and client 0x00000000
2017-11-17 15:28:48,Local5.Debug,172.16.0.200,584790: 583860: Nov 17 20:28:50.062: RADIUS/ENCODE(00000000):Orig. component type = Invalid
2017-11-17 15:28:48,Local5.Debug,172.16.0.200,"584791: 583861: Nov 17 20:28:50.062: RADIUS/ENCODE(00000000): dropping service type, ""radius-server attribute 6 on-for-login-auth"" is off"
2017-11-17 15:28:48,Local5.Debug,172.16.0.200,584792: 583862: Nov 17 20:28:50.062: RADIUS(00000000): Config NAS IP: 172.16.0.200
2017-11-17 15:28:48,Local5.Debug,172.16.0.200,584793: 583863: Nov 17 20:28:50.062: RADIUS(00000000): Config NAS IPv6: ::
2017-11-17 15:28:48,Local5.Debug,172.16.0.200,584794: 583864: Nov 17 20:28:50.062: RADIUS(00000000): sending
2017-11-17 15:28:48,Local5.Debug,172.16.0.200,584795: 583865: Nov 17 20:28:50.062: RADIUS/DECODE(00000000): There is no General DB. Want server details may not be specified
2017-11-17 15:28:48,Local5.Debug,172.16.0.200,584796: 583866: Nov 17 20:28:50.062: RADIUS: nas-port-id(87) is not found in the request
2017-11-17 15:28:49,Local5.Debug,172.16.0.200,"584797: 583867: Nov 17 20:28:50.062: RADIUS(00000000): Send Access-Request to 172.16.1.73:1812 onvrf(0) id 1645/90, len 51"
2017-11-17 15:28:49,Local5.Debug,172.16.0.200,584798: 583868: Nov 17 20:28:50.062: RADIUS: authenticator 12 5E CF B1 19 A9 79 1D - FA 06 6E D0 FE 3C 8E E3
2017-11-17 15:28:49,Local5.Debug,172.16.0.200,584799: 583869: Nov 17 20:28:50.062: RADIUS: User-Password [2] 18 *
2017-11-17 15:28:49,Local5.Debug,172.16.0.200,584800: 583870: Nov 17 20:28:50.062: RADIUS: User-Name [1] 7 "dummy"
2017-11-17 15:28:49,Local5.Debug,172.16.0.200,584801: 583871: Nov 17 20:28:50.062: RADIUS: NAS-IP-Address [4] 6 172.16.0.200
2017-11-17 15:28:49,Local5.Debug,172.16.0.200,584802: 583872: Nov 17 20:28:50.062: RADIUS(00000000): Sending a IPv4 Radius Packet
2017-11-17 15:28:49,Local5.Debug,172.16.0.200,584803: 583873: Nov 17 20:28:50.062: RADIUS(00000000): Started 5 sec timeout
2017-11-17 15:28:51,Local5.Debug,172.16.0.200,"584804: 583874: Nov 17 20:28:52.074: RADIUS: Received from id 1645/90 172.16.1.73:1812, Access-Reject, len 20"
2017-11-17 15:28:51,Local5.Debug,172.16.0.200,584805: 583875: Nov 17 20:28:52.074: RADIUS: authenticator 18 CB CA 21 5D F1 E2 C9 - 28 B9 99 39 45 86 C5 BD
2017-11-17 15:28:51,Local5.Debug,172.16.0.200,584806: 583876: Nov 17 20:28:52.074: RADIUS/DECODE(00000000): There is no General DB. Reply server details may not be recorded
And the mac is no longer listed in the address-table (attachment after-replug.txt).
Now, when I restart switchport from packetfence it restarts port 5/1, as expected, but 5/1 is mac 1866.da0f.a83a.
[cid:image002.png@01D35FBF.46218330]
My apologies for the length of this, just trying to get as much detail as possible. Hoping something jumps out that I'm missing.
Thanks
Darryl
Oh, and here is the cdp neighbors from the previous post, in case it is of interest.
PhoneRoomChassis_Pom.200#sh cdp neighbors
Capability Codes: R - Router, T - Trans Bridge, B - Source Route Bridge
S - Switch, H - Host, I - IGMP, r - Repeater, P - Phone,
D - Remote, C - CVTA, M - Two-port Mac Relay
Device ID Local Intrfce Holdtme Capability Platform Port ID
DataRoom_Top.198 Ten 4/1 132 S I WS-C3560E Ten 0/1
ServerRoom_Top.195
Ten 3/1 152 S I WS-C3560E Ten 0/1
pomeroy_cisco.core.local
Gig 1/1 140 R 7206VXR Gig 6/0
pomeroy_cisco.core.local
Gig 6/48 175 R 7206VXR Gig 0/2
pomeroy_cisco.core.local
Gig 2/46 139 R 7206VXR Fas 4/0
Prep Stack Gig 7/47 175 R N3048 Gi1/0/1
Walsh_PhoneRoom_Top.199
Gig 5/47 177 S I WS-C3560E Gig 0/1
Total cdp entries displayed : 7
All ports connected to pc's have same config:
interface GigabitEthernet5/1
switchport mode access
authentication control-direction in
authentication host-mode multi-auth
authentication order dot1x mab
authentication priority dot1x mab
authentication port-control auto
authentication periodic
authentication timer reauthenticate 19200
authentication timer restart 28800
authentication violation replace
mab
no snmp trap link-status
dot1x pae authenticator
dot1x timeout quiet-period 2
dot1x timeout tx-period 3
macro description packetfence-desktop
spanning-tree portfast
spanning-tree bpduguard enable
end
From: Fabrice Durand [mailto:fd...@in...]
Sent: Friday, November 17, 2017 10:09 AM
To: Sokolowski, Darryl <DS...@ea...>; pac...@li...
Subject: Re: [PacketFence-users] auth request from wrong switch
Hum ok, really weird.
It looks that first when the device connect on the port 2/43 802.1x failed so it start mac auth but just after that the port goes down and a new request is coming from the port 5/3.
When this happen, can you check in the mac-address-table where is the mac address (before and after) ?
Is it a stack of switches ?
Does the issue occur all the time on the same physical switch ?
Le 2017-11-16 à 22:52, Sokolowski, Darryl a écrit :
Hi Fabrice,
Yes, those ports are switchports plugged directly to pcs. Not uplink.
Show cdp neighbors returns expected ports, but none of those in question here.
Thanks
Darryl
-------- Original message --------
From: Durand fabrice via PacketFence-users <pac...@li...><mailto:pac...@li...>
Date: 11/16/17 7:48 PM (GMT-05:00)
To: pac...@li...<mailto:pac...@li...>
Cc: Durand fabrice <fd...@in...><mailto:fd...@in...>
Subject: Re: [PacketFence-users] auth request from wrong switch
Just to be sure, the port 5/3 and 2/43 are switch port , no uplink ?
Does "show cdp neighbors" return one of these ports ?
Le 2017-11-16 à 17:46, Sokolowski, Darryl via PacketFence-users a écrit :
Another thing I noticed is that if I go into PF and restart the switchport from the node details, it will authenticate as dot1x.
When it fails, it seems it is trying wired mac auth. When it does wired mac auth, it says it's successful, but on a port that is something other than where it is really plugged in, so no network access.
If I unplug the nic, and plug it back in, it does not work, only when I restart the port from PF does it work properly and authenticate as dot1x.
From: Sokolowski, Darryl via PacketFence-users [mailto:pac...@li...]
Sent: Thursday, November 16, 2017 10:34 AM
To: pac...@li...<mailto:pac...@li...>; Jason Sloan <jas...@gm...><mailto:jas...@gm...>
Cc: Sokolowski, Darryl <DS...@ea...><mailto:DS...@ea...>
Subject: Re: [PacketFence-users] auth request from wrong switch
Hi again,
This is weird, I don't know what it means.
A machine starts up, shows up on port 2/43, then it appears for some reason it gets authorized on a different port right after that. The first port it appears on, 2/43 is the real port it's plugged into. Then right after that, it appears on 5/3, and that's when I think it gets kicked off the network, since now the switch thinks it's on 5/3. There are no minihubs in the way, these machines plug directly into their respective ports.
I attached a good bit of the debug log, but didn't want to send the whole thing, it's very long. Let me know if I need to send more. There is more in the attachment than I pasted below.
I can't figure out why these machines are getting seen on multiple ports.
Thanks for any insight.
Darryl
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,"350287: 350087: Nov 16 12:53:00.279: dot1x-packet:[0026.2d15.049b, Gi2/43] EAPOL canned status packet sent to client 0xAC000094"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,"350288: 350088: Nov 16 12:53:00.279: dot1x-ev:[0026.2d15.049b, Gi2/43] Deleting client 0xAC000094 (0026.2d15.049b)"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,"350289: 350089: Nov 16 12:53:00.279: dot1x-ev:[0026.2d15.049b, Gi2/43] Delete auth client (0xAC000094) message"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350290: 350090: Nov 16 12:53:00.279: dot1x-ev:Auth client ctx destroyed
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350291: 350091: Nov 16 12:53:00.279: RADIUS/ENCODE(00000000):Orig. component type = Invalid
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350292: 350092: Nov 16 12:53:00.279: RADIUS(00000000): Config NAS IP: 172.16.0.200
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350293: 350093: Nov 16 12:53:00.279: RADIUS(00000000): Config NAS IPv6: ::
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350294: 350094: Nov 16 12:53:00.279: RADIUS(00000000): sending
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,"350295: 350095: Nov 16 12:53:00.279: RADIUS(00000000): Send Access-Request to 172.16.1.73:1812 onvrf(0) id 1645/251, len 259"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350296: 350096: Nov 16 12:53:00.279: RADIUS: authenticator 7A 07 65 33 17 CD 20 47 - 3C 6A 23 4C 46 19 31 B0
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350297: 350097: Nov 16 12:53:00.279: RADIUS: User-Name [1] 14 "00262d15049b"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350298: 350098: Nov 16 12:53:00.279: RADIUS: User-Password [2] 18 *
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350299: 350099: Nov 16 12:53:00.279: RADIUS: Service-Type [6] 6 Call Check [10]
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,"350300: 350100: Nov 16 12:53:00.279: RADIUS: Vendor, Cisco [26] 31 "
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350301: 350101: Nov 16 12:53:00.279: RADIUS: Cisco AVpair [1] 25 "service-type=Call Check"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350302: 350102: Nov 16 12:53:00.279: RADIUS: Framed-MTU [12] 6 1500
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350303: 350103: Nov 16 12:53:00.279: RADIUS: Called-Station-Id [30] 19 "2C-54-2D-A5-A4-D2"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350304: 350104: Nov 16 12:53:00.279: RADIUS: Calling-Station-Id [31] 19 "00-26-2D-15-04-9B"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350305: 350105: Nov 16 12:53:00.279: RADIUS: Message-Authenticato[80] 18
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350306: 350106: Nov 16 12:53:00.279: RADIUS: 2D 71 9B 1E 20 7F 88 F3 6E D2 37 C1 40 61 D7 1B [ -q n7@a]
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350307: 350107: Nov 16 12:53:00.279: RADIUS: EAP-Key-Name [102] 2 *
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,"350308: 350108: Nov 16 12:53:00.279: RADIUS: Vendor, Cisco [26] 49 "
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350309: 350109: Nov 16 12:53:00.279: RADIUS: Cisco AVpair [1] 43 "audit-session-id=AC1000C80000B2D674FDDBB6"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,"350310: 350110: Nov 16 12:53:00.279: RADIUS: Vendor, Cisco [26] 18 "
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350311: 350111: Nov 16 12:53:00.279: RADIUS: Cisco AVpair [1] 12 "method=mab"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350312: 350112: Nov 16 12:53:00.279: RADIUS: NAS-IP-Address [4] 6 172.16.0.200
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350313: 350113: Nov 16 12:53:00.279: RADIUS: NAS-Port-Id [87] 21
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350314: "GigabitEthernet2/43"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350315: 350114: Nov 16 12:53:00.279: RADIUS: NAS-Port-Type [61] 6 Ethernet [15]
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350316: 350115: Nov 16 12:53:00.279: RADIUS: NAS-Port [5] 6 50243
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350317: 350116: Nov 16 12:53:00.279: RADIUS(00000000): Sending a IPv4 Radius Packet
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350318: 350117: Nov 16 12:53:00.279: RADIUS(00000000): Started 5 sec timeout
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,"350319: 350118: Nov 16 12:53:00.483: RADIUS: Received from id 1645/251 172.16.1.73:1812, Access-Accept, len 36"
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350320: 350119: Nov 16 12:53:00.483: RADIUS: authenticator EE 56 4E 55 B5 FF D8 E4 - E6 0A 75 4C 50 E6 99 9C
2017-11-16 07:52:59,Local5.Debug,172.16.0.200,350321: 350120: Nov 16 12:53:00.483: RADIUS: Tunnel-Type [64] 6 00:VLAN [13]
2017-11-16 07:53:00,Local5.Debug,172.16.0.200,350322: 350121: Nov 16 12:53:00.483: RADIUS: Tunnel-Private-Group[81] 4 "18"
2017-11-16 07:53:00,Local5.Debug,172.16.0.200,350323: 350122: Nov 16 12:53:00.483: RADIUS: Tunnel-Medium-Type [65] 6 00:ALL_802 [6]
2017-11-16 07:53:00,Local5.Debug,172.16.0.200,350324: 350123: Nov 16 12:53:00.483: RADIUS(00000000): Received from id 1645/251
2017-11-16 07:53:00,Local5.Debug,172.16.0.200,350325: 350124: Nov 16 12:53:01.131: RADIUS/ENCODE(00000000):Orig. component type = Invalid
2017-11-16 07:53:00,Local5.Debug,172.16.0.200,350326: 350125: Nov 16 12:53:01.131: RADIUS(00000000): Config NAS IP: 172.16.0.200
2017-11-16 07:53:00,Local5.Debug,172.16.0.200,350327: 350126: Nov 16 12:53:01.131: RADIUS(00000000): Config NAS IPv6: ::
2017-11-16 07:53:00,Local5.Debug,172.16.0.200,350328: 350127: Nov 16 12:53:01.131: RADIUS(00000000): Sending a IPv4 Radius Packet
2017-11-16 07:53:00,Local5.Debug,172.16.0.200,350329: 350128: Nov 16 12:53:01.131: RADIUS(00000000): Started 5 sec timeout
2017-11-16 07:53:01,Local5.Debug,172.16.0.200,"350330: 350129: Nov 16 12:53:01.163: RADIUS: Received from id 1646/204 172.16.1.73:1813, Accounting-response, len 35"
2017-11-16 07:55:07,Local5.Debug,172.16.0.200,350331: 350130: Nov 16 12:55:06.950: dot1x-ev:[Gi2/43] Interface state changed to DOWN
2017-11-16 07:55:07,Local5.Debug,172.16.0.200,350332: 350131: Nov 16 12:55:06.954: dot1x-ev:[Gi2/43] Clearing all supplicant instances
2017-11-16 07:55:07,Local5.Debug,172.16.0.200,350333: 350132: Nov 16 12:55:06.954: RADIUS/ENCODE(00000000):Orig. component type = Invalid
2017-11-16 07:55:07,Local5.Debug,172.16.0.200,350334: 350133: Nov 16 12:55:06.954: RADIUS(00000000): Config NAS IP: 172.16.0.200
2017-11-16 07:55:07,Local5.Debug,172.16.0.200,350335: 350134: Nov 16 12:55:06.954: RADIUS(00000000): Config NAS IPv6: ::
2017-11-16 07:55:07,Local5.Debug,172.16.0.200,350336: 350135: Nov 16 12:55:06.954: RADIUS(00000000): Sending a IPv4 Radius Packet
2017-11-16 07:55:07,Local5.Debug,172.16.0.200,350337: 350136: Nov 16 12:55:06.954: RADIUS(00000000): Started 5 sec timeout
2017-11-16 07:55:07,Local5.Debug,172.16.0.200,"350338: 350137: Nov 16 12:55:07.046: RADIUS: Received from id 1646/205 172.16.1.73:1813, Accounting-response, len 35"
2017-11-16 07:55:07,Local5.Notice,172.16.0.200,"350339: 350138: Nov 16 12:55:07.950: %LINEPROTO-5-UPDOWN: Line protocol on Interface GigabitEthernet2/43, changed state to down"
2017-11-16 07:55:09,Local5.Error,172.16.0.200,"350340: 350139: Nov 16 12:55:08.950: %LINK-3-UPDOWN: Interface GigabitEthernet2/43, changed state to down"
2017-11-16 07:55:11,Local5.Debug,172.16.0.200,350341: 350140: Nov 16 12:55:12.290: dot1x_auth Gi5/3: initial state auth_initialize has enter
2017-11-16 07:55:11,Local5.Debug,172.16.0.200,"350342: 350141: Nov 16 12:55:12.290: dot1x-sm:[0026.2d15.049b, Gi5/3] 0x0E000095: initialising"
2017-11-16 07:55:11,Local5.Debug,172.16.0.200,"350343: 350142: Nov 16 12:55:12.290: dot1x_auth Gi5/3: during state auth_initialize, got event 0(cfg_auto)"
2017-11-16 07:55:11,Local5.Debug,172.16.0.200,350344: 350143: Nov 16 12:55:12.290: @@@ dot1x_auth Gi5/3: auth_initialize -> auth_disconnected
2017-11-16 07:55:11,Local5.Debug,172.16.0.200,"350345: 350144: Nov 16 12:55:12.290: dot1x-sm:[0026.2d15.049b, Gi5/3] 0x0E000095: disconnected"
2017-11-16 07:55:11,Local5.Debug,172.16.0.200,350346: 350145: Nov 16 12:55:12.290: dot1x_auth Gi5/3: idle during state auth_disconnected
2017-11-16 07:55:11,Local5.Debug,172.16.0.200,350347: 350146: Nov 16 12:55:12.290: @@@ dot1x_auth Gi5/3: auth_disconnected -> auth_restart
2017-11-16 07:55:11,Local5.Debug,172.16.0.200,"350348: 350147: Nov 16 12:55:12.290: dot1x-sm:[0026.2d15.049b, Gi5/3] 0x0E000095: entering restart"
2017-11-16 07:55:11,Local5.Debug,172.16.0.200,"350349: 350148: Nov 16 12:55:12.290: dot1x-ev:[0026.2d15.049b, Gi5/3] Sending create new context event to EAP for 0x0E000095 (0026.2d15.049b)"
From: Sokolowski, Darryl via PacketFence-users [mailto:pac...@li...]
Sent: Tuesday, November 14, 2017 5:44 PM
To: Jason Sloan <jas...@gm...<mailto:jas...@gm...>>
Cc: Sokolowski, Darryl <DS...@ea...<mailto:DS...@ea...>>; pac...@li...<mailto:pac...@li...>
Subject: Re: [PacketFence-users] auth request from wrong switch
This is happening to a few ports, but not all ports, I counted 12 so far.
I got some of the debug output, and looking thru it.
I set the ip radius source-interface on the 2 switches that seems to be crossing each other.
Thanks
Darryl
From: Jason Sloan [mailto:jas...@gm...]
Sent: Tuesday, November 14, 2017 2:11 PM
To: Sokolowski, Darryl <DS...@ea...<mailto:DS...@ea...>>
Cc: pac...@li...<mailto:pac...@li...>
Subject: Re: [PacketFence-users] auth request from wrong switch
Depends on how the authentication request is sent. Is this happening for one client/port on the switch or the entire switch?
Try setting the source interface:
conf t
ip radius source-interface X (in your case you like
Since your switches are not under heavy load you can flip on some debugs and take a look at the authentication and make sure it is sourced as expected.
debug dot1x all
debug authentication all
debug radius authentication
On Tue, Nov 14, 2017 at 12:32 PM, Sokolowski, Darryl <DS...@ea...<mailto:DS...@ea...>> wrote:
Oh, ok. Since we have a ring, all interfaces comprising the ring are forwarding except one.
All switches are trunked to each other over the ring. I am certain there are no extra errant extra uplinks, since we are just beginning to use the switches and not much plugged into them yet.
How could the blocking cause a machine to appear on a different port?
I did forget to include one switch is a 4507 chassis. Don't think this should matter.
Thanks
Darryl
From: Jason Sloan [mailto:jas...@gm...<mailto:jas...@gm...>]
Sent: Tuesday, November 14, 2017 11:05 AM
To: Sokolowski, Darryl <DS...@ea...<mailto:DS...@ea...>>
Cc: pac...@li...<mailto:pac...@li...>
Subject: Re: [PacketFence-users] auth request from wrong switch
show spanning-tree vlan X (in your case vlan 1)
Check and see if all ports are in a forwarding state, or at least the ones you expect to be in a forwarding state are forwarding. If left to its own devices, sometimes spanning tree can make the wrong decision during an election. You can manually set spanning tree priorities on your up-links if this is the case. If the switches have vlan 1 trunked to each other this may be something to look at, otherwise probably not an issue.
On Tue, Nov 14, 2017 at 10:10 AM, Sokolowski, Darryl <DS...@ea...<mailto:DS...@ea...>> wrote:
Hi thanks for the response.
Sorry, I should have offered more detail on environment.
All switches are Cisco 3560E.
172.16.0.196 is a switch, all vlans exist on all switches, all switches use vlan1 for management, they are trunked via 10GB ring.
I did not set radius source interface.
No NATs.
Sorry, what do you mean by reviewing spanning tree blocks?
From: Jason Sloan [mailto:jas...@gm...<mailto:jas...@gm...>]
Sent: Monday, November 13, 2017 4:23 PM
To: pac...@li...<mailto:pac...@li...>
Cc: Sokolowski, Darryl <DS...@ea...<mailto:DS...@ea...>>
Subject: Re: [PacketFence-users] auth request from wrong switch
A few questions.
172.16.0.196 - is that a switch at all? If so, is that switch on the same vlan? Have you reviewed your spanning-tree blocks? Are you able to set a radius source interface? If so, is it set to the appropriate SVI / L3 link? Any NATs in the topology?
On Mon, Nov 13, 2017 at 3:40 PM, Sokolowski, Darryl via PacketFence-users <pac...@li...<mailto:pac...@li...>> wrote:
Hi all,
I have a strange problem I can't see the reason for,
I have machines that get "stuck" unable to access the network seems like because the 802.1x authentication request is coming from a switch that the device isn't plugged into.
In this case, I have a computer (18:66:da:1e:06:0a) plugged into switch with IP 172.16.0.200.
In the log it shows that the request is coming from 172.16.0.196, and authorizes the machine and assigns the correct vlan, but it is assigned to the wrong switch, so the client never can access the network.
Further, there is already the correct machine (64:00:6a:7c:34:ce) authorized on that port because that machine really does plug in there.
Nov 13 03:12:37 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:18:66:da:1e:06:0a] handling radius autz request: from switch_ip => (172.16.0.196), connection_type => WIRED_MAC_AUTH,switch_mac => (00:23:ac:d0:ca:8a), mac => [18:66:da:1e:06:0a], port => 10110, username => "1866da1e060a" (pf::radius::authorize)
Nov 13 03:12:37 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:18:66:da:1e:06:0a] Instantiate profile default (pf::Connection::ProfileFactory::_from_profile)
Nov 13 03:12:37 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:18:66:da:1e:06:0a] Connection type is WIRED_MAC_AUTH. Getting role from node_info (pf::role::getRegisteredRole)
Nov 13 03:12:37 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:18:66:da:1e:06:0a] Username was defined "1866da1e060a" - returning role 'Employee' (pf::role::getRegisteredRole)
Nov 13 03:12:37 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:18:66:da:1e:06:0a] PID: "CORE\amblerd", Status: reg Returned VLAN: (undefined), Role: Employee (pf::role::fetchRoleForNode)
Nov 13 03:12:37 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:18:66:da:1e:06:0a] (172.16.0.196) Added VLAN 18 to the returned RADIUS Access-Accept (pf::Switch::returnRadiusAccessAccept)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] handling radius autz request: from switch_ip => (172.16.0.196), connection_type => Ethernet-EAP,switch_mac => (00:23:ac:d0:ca:8a), mac => [64:00:6a:7c:34:ce], port => 10110, username => "host/LoboA7.CORE.LOCAL" (pf::radius::authorize)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] is doing machine auth with account 'host/LoboA7.CORE.LOCAL'. (pf::radius::authorize)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] Instantiate profile Earthcolor_Owned (pf::Connection::ProfileFactory::_from_profile)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] Found authentication source(s) : 'AD-Auth' for realm 'null' (pf::config::util::filter_authentication_sources)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) WARN: [mac:64:00:6a:7c:34:ce] Calling match with empty/invalid rule class. Defaulting to 'authentication' (pf::authentication::match2)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] Using sources AD-Auth for matching (pf::authentication::match2)
Nov 13 03:12:52 pf1 pfqueue: pfqueue(9628) INFO: [mac:unknown] undefined source id provided (pf::lookup::person::lookup_person)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] Found authentication source(s) : 'AD-Auth' for realm 'null' (pf::config::util::filter_authentication_sources)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] Using sources AD-Auth for matching (pf::authentication::match2)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] Username was NOT defined or unable to match a role - returning node based role 'Employee' (pf::role::getRegisteredRole)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] PID: "host/LoboA7.CORE.LOCAL", Status: reg Returned VLAN: (undefined), Role: Employee (pf::role::fetchRoleForNode)
Nov 13 03:12:52 pf1 packetfence_httpd.aaa: httpd.aaa(24173) INFO: [mac:64:00:6a:7c:34:ce] (172.16.0.196) Added VLAN 18 to the returned RADIUS Access-Accept (pf::Switch::returnRadiusAccessAccept)
I can't figure out what's going on here.
Anyone seen this and can you point me how to make it right?
Thanks
Darryl
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
PacketFence-users mailing list
Pac...@li...<mailto:Pac...@li...>
https://lists.sourceforge.net/lists/listinfo/packetfence-users
________________________________
>>> CONFIDENTIALITY NOTICE <<<
This electronic mail (e-mail) message, including any and/or all attachments, is for the sole use of the intended recipient(s), and may contain confidential and/or privileged information, pertaining to business conducted under the direction and supervision of EarthColor, Inc. All e-mail messages, which may have been established as expressed views and/or opinions (stated either within the e-mail message or any of its attachments), are left to the sole responsibility of that of the sender, and are not necessarily attributed to EarthColor, Inc. Unauthorized interception, review, use, disclosure or distribution of any such information contained within this e-mail message and/or its attachment(s), is(are) strictly prohibited. If you are not the intended recipient, please contact the sender by replying to this e-mail message, along with the destruction of all copies of the original e-mail message (along with any attachments).
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
PacketFence-users mailing list
Pac...@li...<mailto:Pac...@li...>
https://lists.sourceforge.net/lists/listinfo/packetfence-users
--
Fabrice Durand
fd...@in...<mailto:fd...@in...> :: +1.514.447.4918 (x135) :: www.inverse.ca<http://www.inverse.ca>
Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence (http://packetfence.org)
|
