C3850 MacSec not working against C3560CG with some PMKs

vladakoci · ‎04-27-2015

I have two C3560CG switches that I am using to encrypt traffic on a 1G fiber link between a line card on C4510R+E ( not MacSec capable ) and C3850. As C3850 is now supposed to support MacSec, I tried and wanted to remove the C3560CG switch in front of C3850 and have MacSec terminated directly on C3850.

Surprisingly this does not work, even if the config is the same. I tried couple of things and realized it does not work with some PMKs, but works with some others.

I have this config on C3850 side:

!

interface GigabitEthernet1/1/1

switchport access vlan 40

switchport mode access

switchport nonegotiate

ip arp inspection trust

cts manual

no propagate sgt

sap pmk 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F mode-list gcm-encrypt

ip dhcp snooping trust

!

and this on C3560CG side:

!

interface GigabitEthernet0/9

switchport access vlan 40

switchport mode access

switchport nonegotiate

ip arp inspection trust

media-type sfp

cts manual

no propagate sgt

sap pmk 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10044D5B1C377DCDFDF517F mode-list gcm-encrypt

ip dhcp snooping trust

I am getting these errors:

Apr 27 11:30:16.943 CEST: %CTS-6-PORT_UNAUTHORIZED: Port unauthorized for int(Gi0/9)

on C3560CG side:

and

Apr 27 11:29:33.654 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

On C3850 side.

Interesting is that if I change to this PMK on both sides
cts manual

sap pmk 1234abcdef mode-list gcm-encrypt null no-encap

no propagate sgt

it works.

I’ve tried couple of other PMKs, they do not work either.

C3560CG is 15.0(2)SE4, C3850 is 03.07.00E.

Here is CTS debug taken from both switches:

Building configuration...

Current configuration : 318 bytes

!

interface GigabitEthernet0/9

switchport access vlan 40

switchport mode access

switchport nonegotiate

ip arp inspection trust

shutdown

media-type sfp

cts manual

no propagate sgt

sap pmk 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10044D5B1C377DCDFDF517F mode-list gcm-encrypt

ip dhcp snooping trust

C3560CG#

C3560CG#

C3560CG#debug cts all

All cts debugging is on

C3560CG#conf t

Enter configuration commands, one per line. End with CNTL/Z.

C3560CG(config)#int g0/9

C3560CG(config-if)#

Apr 27 11:29:30.194 CEST: CTS-SXP-CONN:sxp_process_message_event = CTS_SXPMSG_REQUEST

Apr 27 11:29:30.194 CEST: CTS-SXP-CONN:sxp_process_request CTS_SXPMSG_REQ_CONN_NVGEN

Apr 27 11:29:30.194 CEST: CTS-SXP-CONN:cts_get_next_sxpconn_cli

Apr 27 11:29:30.194 CEST: CTS-SXP-INTNL:sxp_process_request boolean set

Apr 27 11:29:30.194 CEST: CTS-SXP-CONN:

% SXP:Note that SXP is not enabled

Apr 27 11:29:30.200 CEST: CTS-SXP-INTNL:sxp_send_request set boolean after

Apr 27 11:29:30.787 CEST: CTS-SXP-CONN:sxp_process_message_event = CTS_SXPMSG_REQUEST

Apr 27 11:29:30.787 CEST: CTS-SXP-CONN:sxp_process_request CTS_SXPMSG_REQ_CONN_NVGEN

C3560CG(config-if)#no s

Apr 27 11:29:30.787 CEST: CTS-SXP-CONN:cts_get_next_sxpconn_cli

Apr 27 11:29:30.787 CEST: CTS-SXP-INTNL:sxp_process_request boolean set

Apr 27 11:29:30.787 CEST: CTS-SXP-CONN:

% SXP:Note that SXP is not enabled

Apr 27 11:29:30.787 CEST: CTS-SXP-INTNL:sxp_send_request set boolean after

C3560CG(config-if)#no sh

C3560CG(config-if)#

Apr 27 11:29:33.540 CEST: cts_swif_comingup called for Gi0/9

Apr 27 11:29:33.540 CEST: cts_swif_comingup done for Gi0/9

Apr 27 11:29:33.634 CEST: CTS-ifc-ev: cts_port_link_comingup Gi0/9

Apr 27 11:29:33.634 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:33.634 CEST: CTS-ifc-ev:

CTS process: received msg_id CTS_IFC_MSG_LINK_UP

Apr 27 11:29:33.634 CEST: cts_ifc GigabitEthernet0/9, INIT: during state ifc_init, got event 0(ifc_link_up)

Apr 27 11:29:33.634 CEST: @@@ cts_ifc GigabitEthernet0/9, INIT: ifc_init -> ifc_authenticating

Apr 27 11:29:33.634 CEST: CTS-ifc-ev: Entering AUTHENTICATING state GigabitEthernet0/9,

Apr 27 11:29:33.634 CEST: CTS-ifc-ev: In CTS MANUAL mode, bypassing authentication.

Apr 27 11:29:33.634 CEST: cts_ifc GigabitEthernet0/9, AUTHENTICATING: during state ifc_authenticating, got event 2(ifc_authc_success)

Apr 27 11:29:33.634 CEST: @@@ cts_ifc GigabitEthernet0/9, AUTHENTICATING: ifc_authenticating -> ifc_authorizing

Apr 27 11:29:33.634 CEST: CTS-ifc-ev: Entering AUTHORIZING state (new) Gi0/9 (peer ),

Apr 27 11:29:33.634 CEST: CTS-ifc-ev: In CTS Manual mode, static policy/dynamic id not configured, bypassing Authz

Apr 27 11:29:33.634 CEST: cts_ifc GigabitEthernet0/9, AUTHENTICATING: during state ifc_authorizing, got event 6(ifc_authz_success)

Apr 27 11:29:33.634 CEST: @@@ cts_ifc GigabitEthernet0/9, AUTHENTICATING: ifc_authorizing -> ifc_sap_negotiating

Apr 27 11:29:33.634 CEST: CTS-ifc-ev: Entering SAP state GigabitEthernet0/9,

Apr 27 11:29:33.634 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:33.634 CEST: CTS SAP ev (Gi0/9): Session started (new).

Apr 27 11:29:33.634 CEST: cts_sap_session_start peer:0000.0000.0000 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10044D5B1C377DCDFDF517F

Apr 27 11:29:33.634 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:33.634 CEST: CTS SAP pk (Gi0/9): Sending message #0:

Apr 27 11:29:33.634 CEST: CTS SAP pk: Sent packet length = 113

Apr 27 11:29:33.634 CEST: CTS SAP pk: Sent packet dump:

06E5F100: 0180C200 00031833

06E5F110: 9DBF8389 888E0203 005F0308 03000000

06E5F120: 00000000 00000000 00000000 00000000

06E5F130: 00000000 00000000 00000000 00000000

06E5F140: 00000000 00000000 00000000 00000000

06E5F150: 00000000 00000000 00000000 00000000

06E5F160: 00000000 00000000 00000000 00000000

06E5F170: 00000000 00000000 00

Apr 27 11:29:33.639 CEST: CTS SAP ev (Gi0/9): Old state: [waiting to restart],

event: [restart timer expired], action: [send message #0] succeeded.

New state: [waiting to receive message #1].

Apr 27 11:29:33.639 CEST: CTS SAP pk: Received packet length = 113

Apr 27 11:29:33.639 CEST: CTS SAP pk: Received packet dump:

06D4A0A0: 0180

06D4A0B0: C2000003 2C3ECFA9 5199888E 0203005F

06D4A0C0: 03080300 00000000 00000000 00000000

06D4A0D0: 00000000 00000000 00000000 00000000

06D4A0E0: 00000000 00000000 00000000 00000000

06D4A0F0: 00000000 00000000 00000000 00000000

06D4A100: 00000000 00000000 00000000 00000000

06D4A110: 00000000 00000000 00000000 000000

Apr 27 11:29:33.639 CEST: CTS SAP ev (Gi0/9): EAPOL-Key message from 2C3E.CFA9.5199.

Apr 27 11:29:33.639 CEST: CTS SAP pk (Gi0/9): Received:

Message Number = 0.

Apr 27 11:29:33.639 CEST: CTS SAP ev (Gi0/9): EAPOL-Key message #0 parsed and validated.

Apr 27 11:29:33.639 CEST: CTS SAP ev (Gi0/9): Our MAC = 1833.9DBF.8389,

peer's MAC = 2C3E.CFA9.5199.

Apr 27 11:29:33.639 CEST: CTS SAP ev (Gi0/9): Old state: [waiting to receive message #1],

event: [received message #0], action: [break tie] succeeded.

New state: [determining role].

Apr 27 11:29:33.639 CEST: cts_sap_generate_pmkid_and_sci auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10044D5B1C377DCDFDF517F

Apr 27 11:29:33.639 CEST: CTS SAP pk (Gi0/9): Sending message #1:

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:33.639 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:29:33.639 CEST: CTS SAP pk: Sent packet dump:

06E60A70: 0180C200 00031833

06E60A80: 9DBF8389 888E0203 008D0300 8B000000

06E60A90: 00000000 000000FE C2ABDC70 1D2E6353

06E60AA0: 1B8834C4 E4801C69 96599943 0F82CED2

06E60AB0: 3DDC5D1D 18017900 00000000 00000000

06E60AC0: 00000000 00000000 00000000 00000000

06E60AD0: 00000000 00000000 00000000 00000000

06E60AE0: 00000000 00000000 2EDD1400 00000310

06E60AF0: A08357BD 691C46DF A82753A5 2EA537DD

06E60B00: 08004096 01400000 00300C00 01000000

06E60B10: 00000100 409603

Apr 27 11:29:33.644 CEST: CTS SAP ev (Gi0/9): Old state: [determining role],

event: [change to authenticator], action: [send message #1] succeeded.

New state: [waiting to receive message #2].

Apr 27 11:29:33.650 CEST: CTS SAP pk: Received packet length = 113

Apr 27 11:29:33.650 CEST: CTS SAP pk: Received packet dump:

06D33FF0: 0180

06D34000: C2000003 2C3ECFA9 5199888E 0203005F

06D34010: 03080300 00000000 00000000 00000000

06D34020: 00000000 00000000 00000000 00000000

06D34030: 00000000 00000000 00000000 00000000

06D34040: 00000000 00000000 00000000 00000000

06D34050: 00000000 00000000 00000000 00000000

06D34060: 00000000 00000000 00000000 000000

Apr 27 11:29:33.650 CEST: CTS SAP ev (Gi0/9): EAPOL-Key message from 2C3E.CFA9.5199.

Apr 27 11:29:33.650 CEST: CTS SAP pk (Gi0/9): Received:

Message Number = 0.

Apr 27 11:29:33.650 CEST: CTS SAP ev (Gi0/9): EAPOL-Key message #0 parsed and validated.

Apr 27 11:29:33.650 CEST: CTS SAP er (Gi0/9): sap_reactive_resend message #1.

Apr 27 11:29:33.650 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:29:33.650 CEST: CTS SAP pk: Sent packet dump:

C3560CG(config-if)#

068049E0: 0180C200 00031833 9DBF8389

068049F0: 888E0203 008D0300 8B000000 00000000

06804A00: 000001FE C2ABDC70 1D2E6353 1B8834C4

06804A10: E4801C69 96599943 0F82CED2 3DDC5D1D

06804A20: 18017900 00000000 00000000 00000000

06804A30: 00000000 00000000 00000000 00000000

06804A40: 00000000 00000000 00000000 00000000

06804A50: 00000000 2EDD1400 00000310 A08357BD

06804A60: 691C46DF A82753A5 2EA537DD 08004096

06804A70: 01400000 00300C00 01000000 00000100

06804A80: 409603

Apr 27 11:29:33.650 CEST: CTS SAP er (Gi0/9): Resent message #1.

Apr 27 11:29:34.646 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:29:34.646 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:29:34.646 CEST: CTS SAP pk: Sent packet dump:

06803D60: 0180C200 00031833 9DBF8389

06803D70: 888E0203 008D0300 8B000000 00000000

06803D80: 000002FE C2ABDC70 1D2E6353 1B8834C4

06803D90: E4801C69 96599943 0F82CED2 3DDC5D1D

06803DA0: 18017900 00000000 00000000 00000000

06803DB0: 00000000 00000000 00000000 00000000

06803DC0: 00000000 00000000 00000000 00000000

06803DD0: 00000000 2EDD1400 00000310 A08357BD

06803DE0: 691C46DF A82753A5 2EA537DD 08004096

06803DF0: 01400000 00300C00 01000000 00000100

06803E00: 409603

Apr 27 11:29:34.646 CEST: CTS SAP er (Gi0/9): Message #1 sent 2 times.

Resend timer set to 2 sec.

C3560CG(config-if)#

Apr 27 11:29:35.537 CEST: %LINK-3-UPDOWN: Interface GigabitEthernet0/9, changed state to up

Apr 27 11:29:36.649 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:29:36.649 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:29:36.649 CEST: CTS SAP pk: Sent packet dump:

06802140: 0180C200 00031833 9DBF8389

06802150: 888E0203 008D0300 8B000000 00000000

06802160: 000003FE C2ABDC70 1D2E6353 1B8834C4

06802170: E4801C69 96599943 0F82CED2 3DDC5D1D

06802180: 18017900 00000000 00000000 00000000

06802190: 00000000 00000000 00000000 00000000

068021A0: 00000000 00000000 00000000 00000000

068021B0: 00000000 2EDD1400 00000310 A08357BD

068021C0: 691C46DF A82753A5 2EA537DD 08004096

068021D0: 01400000 00300C00 01000000 00000100

C3560CG(config-if)#

068021E0: 409603

Apr 27 11:29:36.649 CEST: CTS SAP er (Gi0/9): Message #1 sent 3 times.

Resend timer set to 4 sec.

C3560CG(config-if)#

Apr 27 11:29:40.649 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:29:40.649 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:29:40.649 CEST: CTS SAP pk: Sent packet dump:

06803400: 0180C200 00031833 9DBF8389

06803410: 888E0203 008D0300 8B000000 00000000

06803420: 000004FE C2ABDC70 1D2E6353 1B8834C4

06803430: E4801C69 96599943 0F82CED2 3DDC5D1D

06803440: 18017900 00000000 00000000 00000000

06803450: 00000000 00000000 00000000 00000000

06803460: 00000000 00000000 00000000 00000000

06803470: 00000000 2EDD1400 00000310 A08357BD

06803480: 691C46DF A82753A5 2EA537DD 08004096

06803490: 01400000 00300C00 01000000 00000100

C3560CG(config-if)#

068034A0: 409603

Apr 27 11:29:40.649 CEST: CTS SAP er (Gi0/9): Message #1 sent 4 times.

Resend timer set to 4 sec.

C3560CG(config-if)#

Apr 27 11:29:44.650 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:29:44.650 CEST: CTS SAP ev (Gi0/9): Max resends (4) reached.

Apr 27 11:29:44.650 CEST: CTS SAP ev (Gi0/9): Waiting to restart after 3 sec.

Apr 27 11:29:44.650 CEST: CTS SAP ev (Gi0/9): Old state: [waiting to receive message #2],

event: [exchange error], action: [wait to restart] succeeded.

New state: [waiting to restart].

C3560CG(config-if)#

Apr 27 11:29:47.654 CEST: CTS SAP er (Gi0/9): Restart timer expired after 3 sec.

Apr 27 11:29:47.654 CEST: cts_sap_generate_pmkid_and_sci auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10044D5B1C377DCDFDF517F

Apr 27 11:29:47.654 CEST: CTS SAP pk (Gi0/9): Sending message #1:

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:47.654 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:29:47.654 CEST: CTS SAP pk: Sent packet dump:

06E60A70: 0180C200 00031833

06E60A80: 9DBF8389 888E0203 008D0300 8B000000

C3560CG(config-if)#

06E60A90: 00000000 000005FE C2ABDC70 1D2E6353

06E60AA0: 1B8834C4 E4801C69 96599943 0F82CED2

06E60AB0: 3DDC5D1D 18017A00 00000000 00000000

06E60AC0: 00000000 00000000 00000000 00000000

06E60AD0: 00000000 00000000 00000000 00000000

06E60AE0: 00000000 00000000 2EDD1400 00000310

06E60AF0: A08357BD 691C46DF A82753A5 2EA537DD

06E60B00: 08004096 01400000 00300C00 01000000

06E60B10: 00000100 409603

Apr 27 11:29:47.654 CEST: CTS SAP ev (Gi0/9): Old state: [waiting to restart],

event: [restart timer expired], action: [send message #1] succeeded.

New state: [waiting to receive message #2].

Apr 27 11:29:48.656 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:29:48.656 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:29:48.656 CEST: CTS SAP pk: Sent packet dump:

068049E0: 0180C200 00031833 9DBF8389

068049F0: 888E0203 008D0300 8B000000 00000000

06804A00: 000006FE C2ABDC70 1D2E6353 1B8834C4

06804A10: E4801C69 96599943 0F82CED2 3DDC5D1D

06804A20: 18017A00 00000000 00000000 00000000

06804A30: 00000000 00000000 00000000 00000000

06804A40: 00000000 00000000 00000000 00000000

06804A50: 00000000 2EDD1400 00000310 A08357BD

06804A60: 691C46DF A82753A5 2EA537DD 08004096

06804A70: 01400000 00300C00 01000000 00000100

06804A80: 409603

Apr 27 11:29:48.656 CEST: CTS SAP er (Gi0/9): Message #1 sent 2 times.

Resend timer set to 2 sec.

C3560CG(config-if)#

Apr 27 11:29:50.659 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:29:50.659 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:29:50.659 CEST: CTS SAP pk: Sent packet dump:

06801E20: 0180C200 00031833 9DBF8389

06801E30: 888E0203 008D0300 8B000000 00000000

06801E40: 000007FE C2ABDC70 1D2E6353 1B8834C4

06801E50: E4801C69 96599943 0F82CED2 3DDC5D1D

06801E60: 18017A00 00000000 00000000 00000000

06801E70: 00000000 00000000 00000000 00000000

06801E80: 00000000 00000000 00000000 00000000

06801E90: 00000000 2EDD1400 00000310 A08357BD

06801EA0: 691C46DF A82753A5 2EA537DD 08004096

06801EB0: 01400000 00300C00 01000000 00000100

C3560CG(config-if)#

06801EC0: 409603

Apr 27 11:29:50.659 CEST: CTS SAP er (Gi0/9): Message #1 sent 3 times.

Resend timer set to 4 sec.

C3560CG(config-if)#

Apr 27 11:29:54.659 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:29:54.659 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:29:54.659 CEST: CTS SAP pk: Sent packet dump:

06E610B0: 0180C200 00031833

06E610C0: 9DBF8389 888E0203 008D0300 8B000000

06E610D0: 00000000 000008FE C2ABDC70 1D2E6353

06E610E0: 1B8834C4 E4801C69 96599943 0F82CED2

06E610F0: 3DDC5D1D 18017A00 00000000 00000000

06E61100: 00000000 00000000 00000000 00000000

06E61110: 00000000 00000000 00000000 00000000

06E61120: 00000000 00000000 2EDD1400 00000310

06E61130: A08357BD 691C46DF A82753A5 2EA537DD

06E61140: 08004096 01400000 00300C00 01000000

C3560CG(config-if)#

06E61150: 00000100 409603

Apr 27 11:29:54.659 CEST: CTS SAP er (Gi0/9): Message #1 sent 4 times.

Resend timer set to 4 sec.

C3560CG(config-if)#

Apr 27 11:29:58.571 CEST: CTS env-data: Time to retry env data download

Apr 27 11:29:58.571 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:58.571 CEST: cts_env_data START: during state env_data_start, got event 0(env_data_request)

Apr 27 11:29:58.571 CEST: @@@ cts_env_data START: env_data_start -> env_data_waiting_rsp

Apr 27 11:29:58.571 CEST: env_data_waiting_rsp_enter: state = WAITING_RESPONSE

Apr 27 11:29:58.571 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:58.571 CEST: cts_aaa_is_fragmented: (CTS env-data SM)NOT-FRAG attr_q(0)

Apr 27 11:29:58.571 CEST: env_data_request_action: state = WAITING_RESPONSE

Apr 27 11:29:58.571 CEST: cts_env_data_is_complete: FALSE, req(x0), rec(x0), expect(x81), complete1(x85), complete2(xB5), complete3(x14B5)

Apr 27 11:29:58.571 CEST: cts_env_data_aaa_req_setup : aaa_id = 11

Apr 27 11:29:58.571 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:58.571 CEST: cts_aaa_req_setup: (CTS env-data SM)Private group appears DEAD, attempt public group

Apr 27 11:29:58.571 CEST: cts_aaa_req_setup: (CTS env-data SM)No CTS public server list configured

Apr 27 11:29:58.571 CEST: cts_aaa_req_setup: (CTS env-data SM)Failed to get AAA method list handle.

Apr 27 11:29:58.571 CEST: env_data_request_action: Failed to setup/send radius request

Apr 27 11:29:58.571 CEST: cts_env_data WAITING_RESPONSE: during state env_data_waiting_rsp, got event 7(env_data_failed)

Apr 27 11:29:58.571 CEST: @@@ cts_env_data WAITING_RESPONSE: env_data_waiting_rsp -> env_data_start

Apr 27 11:29:58.571 CEST: env_data_start_enter: state = START

Apr 27 11:29:58.576 CEST: env_data_error_action: state = START

Apr 27 11:29:58.576 CEST: CTS-ifc-ev: env data reporting to core, result: Failed

Apr 27 11:29:58.576 CEST: CTS-core-ha-ev:cts_env_data_status_sync: status(Failed)

Apr 27 11:29:58.576 CEST: CTS-core-ha-ev:cts_env_data_status_sync: HA chkpt msg(CTS_CORE_SYNC_TAG_ENV_DATA_STATUS), hdr(4FBAC10)(4) body(NULL)size(0)

C3560CG(config-if)#

Apr 27 11:29:58.660 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:29:58.660 CEST: CTS SAP ev (Gi0/9): Max resends (4) reached.

Apr 27 11:29:58.660 CEST: CTS SAP ev (Gi0/9): Waiting to restart after 3 sec.

Apr 27 11:29:58.660 CEST: CTS SAP ev (Gi0/9): Old state: [waiting to receive message #2],

event: [exchange error], action: [wait to restart] succeeded.

New state: [waiting to restart].

C3560CG(config-if)#

Apr 27 11:30:01.664 CEST: CTS SAP er (Gi0/9): Restart timer expired after 3 sec.

Apr 27 11:30:01.664 CEST: cts_sap_generate_pmkid_and_sci auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10044D5B1C377DCDFDF517F

Apr 27 11:30:01.664 CEST: CTS SAP pk (Gi0/9): Sending message #1:

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:30:01.664 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:30:01.664 CEST: CTS SAP pk: Sent packet dump:

06803400: 0180C200 00031833 9DBF8389

06803410: 888E0203 008D0300 8B000000 00000000

C3560CG(config-if)#

06803420: 000009FE C2ABDC70 1D2E6353 1B8834C4

06803430: E4801C69 96599943 0F82CED2 3DDC5D1D

06803440: 18017B00 00000000 00000000 00000000

06803450: 00000000 00000000 00000000 00000000

06803460: 00000000 00000000 00000000 00000000

06803470: 00000000 2EDD1400 00000310 A08357BD

06803480: 691C46DF A82753A5 2EA537DD 08004096

06803490: 01400000 00300C00 01000000 00000100

068034A0: 409603

Apr 27 11:30:01.664 CEST: CTS SAP ev (Gi0/9): Old state: [waiting to restart],

event: [restart timer expired], action: [send message #1] succeeded.

New state: [waiting to receive message #2].

Apr 27 11:30:02.666 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:30:02.666 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:30:02.666 CEST: CTS SAP pk: Sent packet dump:

06E60110: 0180C200 00031833

06E60120: 9DBF8389 888E0203 008D0300 8B000000

06E60130: 00000000 00000AFE C2ABDC70 1D2E6353

06E60140: 1B8834C4 E4801C69 96599943 0F82CED2

06E60150: 3DDC5D1D 18017B00 00000000 00000000

06E60160: 00000000 00000000 00000000 00000000

06E60170: 00000000 00000000 00000000 00000000

06E60180: 00000000 00000000 2EDD1400 00000310

06E60190: A08357BD 691C46DF A82753A5 2EA537DD

06E601A0: 08004096 01400000 00300C00 01000000

06E601B0: 00000100 409603

Apr 27 11:30:02.666 CEST: CTS SAP er (Gi0/9): Message #1 sent 2 times.

Resend timer set to 2 sec.

C3560CG(config-if)#

Apr 27 11:30:04.669 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:30:04.669 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:30:04.669 CEST: CTS SAP pk: Sent packet dump:

06E60D90: 0180C200 00031833

06E60DA0: 9DBF8389 888E0203 008D0300 8B000000

06E60DB0: 00000000 00000BFE C2ABDC70 1D2E6353

06E60DC0: 1B8834C4 E4801C69 96599943 0F82CED2

06E60DD0: 3DDC5D1D 18017B00 00000000 00000000

06E60DE0: 00000000 00000000 00000000 00000000

06E60DF0: 00000000 00000000 00000000 00000000

06E60E00: 00000000 00000000 2EDD1400 00000310

06E60E10: A08357BD 691C46DF A82753A5 2EA537DD

06E60E20: 08004096 01400000 00300C00 01000000

C3560CG(config-if)#

06E60E30: 00000100 409603

Apr 27 11:30:04.669 CEST: CTS SAP er (Gi0/9): Message #1 sent 3 times.

Resend timer set to 4 sec.

C3560CG(config-if)#

Apr 27 11:30:08.669 CEST: CTS SAP er (Gi0/9): Resend timer expired

Apr 27 11:30:08.669 CEST: CTS SAP pk: Sent packet length = 159

Apr 27 11:30:08.669 CEST: CTS SAP pk: Sent packet dump:

06802780: 0180C200 00031833 9DBF8389

06802790: 888E0203 008D0300 8B000000 00000000

068027A0: 00000CFE C2ABDC70 1D2E6353 1B8834C4

068027B0: E4801C69 96599943 0F82CED2 3DDC5D1D

068027C0: 18017B00 00000000 00000000 00000000

068027D0: 00000000 00000000 00000000 00000000

068027E0: 00000000 00000000 00000000 00000000

068027F0: 00000000 2EDD1400 00000310 A08357BD

06802800: 691C46DF A82753A5 2EA537DD 08004096

06802810: 01400000 00300C00 01000000 00000100

C3560CG(config-if)#

06802820: 409603

Apr 27 11:30:08.669 CEST: CTS SAP er (Gi0/9): Message #1 sent 4 times.

Resend timer set to 4 sec.

C3560CG(config-if)#sh

C3560CG(config-if)#

Apr 27 11:30:11.925 CEST: cts_swif_goingdown called for Gi0/9

Apr 27 11:30:11.925 CEST: cts_swif_goingdown done for Gi0/9

Apr 27 11:30:11.936 CEST: CTS-ifc-ev: Interface(Gi0/9) hardware is ADMIN DOWN

Apr 27 11:30:11.936 CEST: CTS-ifc-ev: cts_port_link_state_change:down Gi0/9

Apr 27 11:30:11.936 CEST: CTS-ifc-ev:

CTS process: received msg_id CTS_IFC_MSG_LINK_DOWN

Apr 27 11:30:11.936 CEST: cts_ifc GigabitEthernet0/9, SAP_NEGOTIATING: during state ifc_sap_negotiating, got event 1(ifc_link_down)

Apr 27 11:30:11.936 CEST: @@@ cts_ifc GigabitEthernet0/9, SAP_NEGOTIATING: ifc_sap_negotiating -> ifc_disconnecting

Apr 27 11:30:11.936 CEST: CTS-ifc-ev: Entering DISCONNECTING state

Apr 27 11:30:11.936 CEST: CTS-ifc-ev: previous state = SAP_NEGOTIATING

Apr 27 11:30:11.936 CEST: CTS-ifc-cache: (Gi0/9) flush ALL cache.

Apr 27 11:30:11.936 CEST: CTS-ifc-cache: In Manual mode, no need to flush cache for Gi0/9.

Apr 27 11:30:11.936 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:30:11.936 CEST: CTS-ifc-ev: posting message to CTS core to clean up...

Apr 27 11:30:11.936 CEST: CTS-ifc-ev:

CTS process: received msg_id CTS_IFC_MSG_DISCONNECT

Apr 27 11:30:11.941 CEST: CTS-ifc-ev: Disconnect: cleaning up authz...

Apr 27 11:30:11.941 CEST: CTS-ifc-ev: Disconnect: cleaning up datapath...

Apr 27 11:30:11.941 CEST: CTS-ifc-ev: Disconnect: cleaning up sap...

Apr 27 11:30:11.941 CEST: CTS SAP ev (Gi0/9): Session stopped.

Apr 27 11:30:11.941 CEST: CTS-ifc-ev: Disconnect: cleaning up peer_sgt...

Apr 27 11:30:11.941 CEST: CTS-ifc-ev: Uninstalling peer sgt

Apr 27 11:30:11.941 CEST: CTS-ifc-ev: Disconnect: cleaning up datapath...

Apr 27 11:30:11.941 CEST: CTS-ifc-ev: Disconnect done--restarting IFC state machine

Apr 27 11:30:11.941 CEST: cts_ifc GigabitEthernet0/9, DISCONNECTING: during state ifc_disconnecting, got event 14(ifc_restart)

Apr 27 11:30:11.941 CEST: @@@ cts_ifc GigabitEthernet0/9, DISCONNECTING: ifc_disconnecting -> ifc_held

C3560CG(config-if)#

Apr 27 11:30:11.941 CEST: CTS-ifc-ev: Entering HELD state Gi0/9

Apr 27 11:30:11.941 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:30:11.941 CEST: CTS-ifc-ev: Started hold timer.

C3560CG(config-if)#

Apr 27 11:30:13.933 CEST: %LINK-5-CHANGED: Interface GigabitEthernet0/9, changed state to administratively down

C3560CG(config-if)#do debu

Apr 27 11:30:16.943 CEST: CTS-ifc-ev: cts_ifc_timer_handler

Apr 27 11:30:16.943 CEST: CTS-ifc-ev: HOLD timer expired

Apr 27 11:30:16.943 CEST: cts_ifc GigabitEthernet0/9, HELD: during state ifc_held, got event 11(ifc_hold_timer_expired)

Apr 27 11:30:16.943 CEST: @@@ cts_ifc GigabitEthernet0/9, HELD: ifc_held -> ifc_init

Apr 27 11:30:16.943 CEST: CTS-ifc-ev: HELD->EXIT

Apr 27 11:30:16.943 CEST: CTS-ifc-ev: stopping hold timer

Apr 27 11:30:16.943 CEST: CTS-ifc-ev: Entering INIT state

Apr 27 11:30:16.943 CEST: cts_authz_session_clear_link_obj: link_obj(6515FDC)

Apr 27 11:30:16.943 CEST: %CTS-6-PORT_UNAUTHORIZED: Port unauthorized for int(Gi0/9)

C3560CG(config-if)#do deb

Apr 27 11:30:16.943 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:30:16.943 CEST: CTS-ifc-ev: Interface(Gi0/9) hardware is ADMIN DOWN

Apr 27 11:30:16.943 CEST: CTS-ifc-ev: Gi0/9:Interface is down on Active.

C3560CG(config-if)#

C3560CG(config-if)#^Z

C3560CG#undebu

Apr 27 11:30:22.532 CEST: %SYS-5-CONFIG_I: Configured from console by username on vty0 (10.128.60.229)

C3560CG#undebug all

All possible debugging has been turned off

C3560CG#

C3850#sh runn int g1/1/1

Building configuration...

Current configuration : 322 bytes

!

interface GigabitEthernet1/1/1

switchport access vlan 40

switchport mode access

switchport nonegotiate

ip arp inspection trust

cts manual

no propagate sgt

sap pmk 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F mode-list gcm-encrypt

ip dhcp snooping trust

C3850#

C3850#debug cts all

All cts debugging is on

C3850#

Apr 27 11:29:33.632 CEST: CTS-ifc-ev: cts_port_link_comingup Gi1/1/1

Apr 27 11:29:33.632 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:33.633 CEST: CTS-ifc-ev: CTS process: received msg_id CTS_IFC_MSG_LINK_UP for Gi1/1/1

Apr 27 11:29:33.633 CEST: cts_ifc GigabitEthernet1/1/1, INIT: during state ifc_init, got event 0(ifc_link_up)

Apr 27 11:29:33.633 CEST: @@@ cts_ifc GigabitEthernet1/1/1, INIT: ifc_init -> ifc_authenticating

Apr 27 11:29:33.633 CEST: CTS-ifc-ev: In CTS MANUAL mode, bypassing authentication for Gi1/1/1.

Apr 27 11:29:33.633 CEST: cts_ifc GigabitEthernet1/1/1, AUTHENTICATING: during state ifc_authenticating, got event 2(ifc_authc_success)

Apr 27 11:29:33.633 CEST: @@@ cts_ifc GigabitEthernet1/1/1, AUTHENTICATING: ifc_authenticating -> ifc_authorizing

Apr 27 11:29:33.633 CEST: CTS-ifc-ev: setting up asic to encrypt pause frames for Gi1/1/1

Apr 27 11:29:33.633 CEST: CTS-ifc-ev: In CTS Manual mode, static policy/dynamic id not configured, bypassing Authz for Gi1/1/1

Apr 27 11:29:33.633 CEST: cts_ifc GigabitEthernet1/1/1, AUTHENTICATING: during state ifc_authorizing, got event 6(ifc_authz_success)

Apr 27 11:29:33.633 CEST: @@@ cts_ifc GigabitEthernet1/1/1, AUTHENTICATING: ifc_authorizing -> ifc_sap_negotiating

Apr 27 11:29:33.633 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:33.633 CEST: CTS SAP ev (Gi1/1/1): Session started (new).

Apr 27 11:29:33.633 CEST: cts_sap_session_start CTS SAP ev (Gi1/1/1) peer:0000.0000.0000 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:33.634 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:33.634 CEST: CTS SAP pk (Gi1/1/1): Sending message #0:

Apr 27 11:29:33.634 CEST: CTS SAP pk: Sent packet length = 113

Apr 27 11:29:33.634 CEST: CTS SAP pk: Sent packet dump:

3A666050: 0180C200 00032C3E CFA95199 888E0203

3A666060: 005F0308 03000000 00000000 00000000

3A666070: 00000000 00000000 00000000 00000000

3A666080: 00000000 00000000 00000000 00000000

3A666090: 00000000 00000000 00000000 00000000

3A6660A0: 00000000 00000000 00000000 00000000

3A6660B0: 00000000 00000000 00000000 00000000

3A6660C0: 00

Apr 27 11:29:33.637 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to restart],

event: [restart timer expired], action: [send message #0] succeeded.

New state: [waiting to receive message #1].

Apr 27 11:29:33.641 CEST: CTS SAP pk: Received packet length = 113

Apr 27 11:29:33.641 CEST: CTS SAP pk: Received packet dump:

3B4D0670: 0180 C2000003 18339DBF

3B4D0680: 8389888E 0203005F 03080300 00000000

3B4D0690: 00000000 00000000 00000000 00000000

3B4D06A0: 00000000 00000000 00000000 00000000

3B4D06B0: 00000000 00000000 00000000 00000000

3B4D06C0: 00000000 00000000 00000000 00000000

3B4D06D0: 00000000 00000000 00000000 00000000

3B4D06E0: 00000000 000000

Apr 27 11:29:33.645 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:33.645 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 0.

Apr 27 11:29:33.645 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #0 parsed and validated.

Apr 27 11:29:33.645 CEST: CTS SAP ev (Gi1/1/1): Our MAC = 2C3E.CFA9.5199,

peer's MAC = 1833.9DBF.8389.

Apr 27 11:29:33.645 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #0], action: [break tie] succeeded.

New state: [determining role].

Apr 27 11:29:33.645 CEST: CTS SAP pk (Gi1/1/1): Sending message #0:

Apr 27 11:29:33.645 CEST: CTS SAP pk: Sent packet length = 113

Apr 27 11:29:33.645 CEST: CTS SAP pk: Sent packet dump:

3A666050: 0180C200 00032C3E CFA95199 888E0203

3A666060: 005F0308 03000000 00000000 00000000

3A666070: 00000000 00000000 00000000 00000000

3A666080: 00000000 00000000 00000000 00000000

3A666090: 00000000 00000000 00000000 00000000

3A6660A0: 00000000 00000000 00000000 00000000

3A6660B0: 00000000 00000000 00000000 00000000

3A6660C0: 00

Apr 27 11:29:33.649 CEST: CTS SAP ev (Gi1/1/1): Old state: [determining role],

event: [stay as supplicant], action: [send message #0] succeeded.

New state: [waiting to receive message #1].

Apr 27 11:29:33.649 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:29:33.649 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 00FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 79000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:29:33.654 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:33.654 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:29:33.654 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:33.654 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:29:33.654 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:33.654 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

Apr 27 11:29:33.654 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

Apr 27 11:29:33.656 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:29:33.656 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 01FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 79000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:29:33.661 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:33.661 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:29:33.661 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:33.661 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

C3850#

Apr 27 11:29:33.661 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:33.661 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

Apr 27 11:29:34.650 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:29:34.650 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 02FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 79000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:29:34.655 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:34.655 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:29:34.656 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:34.656 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:29:34.656 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:34.656 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:29:34.656 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

C3850#

Apr 27 11:29:35.624 CEST: %LINK-3-UPDOWN: Interface GigabitEthernet1/1/1, changed state to up

Apr 27 11:29:36.653 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:29:36.653 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 03FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 79000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:29:36.658 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:36.658 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:29:36.658 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:36.658 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:29:36.658 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:36.658 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:29:36.658 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

C3850#

Apr 27 11:29:39.925 CEST: CTS env-data: Time to retry env data download

Apr 27 11:29:39.925 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:39.925 CEST: cts_env_data START: during state env_data_start, got event 0(env_data_request)

Apr 27 11:29:39.925 CEST: @@@ cts_env_data START: env_data_start -> env_data_waiting_rsp

Apr 27 11:29:39.925 CEST: env_data_waiting_rsp_enter: state = WAITING_RESPONSE

Apr 27 11:29:39.925 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:39.925 CEST: cts_aaa_is_fragmented: (CTS env-data SM)NOT-FRAG attr_q(0)

Apr 27 11:29:39.925 CEST: env_data_request_action: state = WAITING_RESPONSE

Apr 27 11:29:39.925 CEST: cts_env_data_is_complete: FALSE, req(x0), rec(x0)

Apr 27 11:29:39.925 CEST: cts_env_data_is_complete: FALSE, req(x0), rec(x0), expect(x81), complete1(x85), complete2(xB5), complete3(x1485)

Apr 27 11:29:39.926 CEST: env_data_request_action: state = WAITING_RESPONSE, received = 0x0 request = 0x0

Apr 27 11:29:39.926 CEST: cts_env_data_aaa_req_setup : aaa_id = 4574

Apr 27 11:29:39.926 CEST: CTS-core-ha-ev:cts_core_ha_is_active :1

Apr 27 11:29:39.926 CEST: cts_aaa_req_setup: (CTS env-data SM)Private group appears DEAD, attempt public group

Apr 27 11:29:39.926 CEST: cts_aaa_req_setup: (CTS env-data SM)No CTS public server list configured

Apr 27 11:29:39.926 CEST: cts_aaa_req_setup: (CTS env-data SM)Failed to get live AAA method list handle.

Apr 27 11:29:39.926 CEST: env_data_request_action: Failed to setup/send radius request

Apr 27 11:29:39.926 CEST: cts_env_data WAITING_RESPONSE: during state env_data_waiting_rsp, got event 7(env_data_failed)

Apr 27 11:29:39.926 CEST: @@@ cts_env_data WAITING_RESPONSE: env_data_waiting_rsp -> env_data_start

Apr 27 11:29:39.926 CEST: env_data_start_enter: state = START

Apr 27 11:29:39.926 CEST: env_data_error_action: state = START

Apr 27 11:29:39.926 CEST: env_data_error_action: state = START, received = 0x0 request = 0x0

C3850#

Apr 27 11:29:39.926 CEST: CTS-ifc-ev: env data reporting to core, result: Failed

Apr 27 11:29:39.926 CEST: CTS-core-ha-ev:cts_env_data_status_sync: sync not allowed

Apr 27 11:29:40.653 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:29:40.653 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 04FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 79000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:29:40.658 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:40.658 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:29:40.658 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:40.658 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:29:40.658 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:40.659 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:29:40.659 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

C3850#

Apr 27 11:29:47.659 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:29:47.659 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 05FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 7A000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:29:47.664 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:47.664 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:29:47.664 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:47.664 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:29:47.664 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:47.664 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:29:47.664 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

Apr 27 11:29:48.660 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:29:48.660 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 06FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 7A000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:29:48.665 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:48.665 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:29:48.665 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:48.665 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:29:48.665 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:48.665 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:29:48.665 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

C3850#

Apr 27 11:29:50.663 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:29:50.663 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 07FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 7A000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:29:50.668 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:50.668 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:29:50.668 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:50.668 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:29:50.668 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:50.668 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:29:50.668 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

C3850#

Apr 27 11:29:54.663 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:29:54.663 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 08FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 7A000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:29:54.668 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:29:54.668 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:29:54.668 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:29:54.668 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:29:54.668 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:29:54.669 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:29:54.669 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

C3850#

Apr 27 11:30:01.669 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:30:01.669 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 09FEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 7B000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:30:01.674 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:30:01.674 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:30:01.674 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:30:01.674 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:30:01.674 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:30:01.674 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:30:01.674 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

Apr 27 11:30:02.670 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:30:02.670 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 0AFEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 7B000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:30:02.675 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:30:02.675 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:30:02.675 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:30:02.675 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:30:02.675 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:30:02.675 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:30:02.675 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

C3850#

Apr 27 11:30:04.672 CEST: CTS SAP pk: Received packet length = 159

Apr 27 11:30:04.672 CEST: CTS SAP pk: Received packet dump:

3B4D1250: 0180 C2000003

3B4D1260: 18339DBF 8389888E 0203008D 03008B00

3B4D1270: 00000000 00000000 0BFEC2AB DC701D2E

3B4D1280: 63531B88 34C4E480 1C699659 99430F82

3B4D1290: CED23DDC 5D1D1801 7B000000 00000000

3B4D12A0: 00000000 00000000 00000000 00000000

3B4D12B0: 00000000 00000000 00000000 00000000

3B4D12C0: 00000000 00000000 00002EDD 14000000

3B4D12D0: 0310A083 57BD691C 46DFA827 53A52EA5

3B4D12E0: 37DD0800 40960140 00000030 0C000100

3B4D12F0: 00000000 01004096 03

Apr 27 11:30:04.677 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message from 1833.9DBF.8389.

Apr 27 11:30:04.677 CEST: CTS-SAP ev: (Gi1/1/1): msg 1 saved for MIC calculation later.

Apr 27 11:30:04.677 CEST: CTS SAP pk (Gi1/1/1): Received:

Message Number = 1.

RSNA Key Data: PMKID = 10A08357 BD691C46 DFA82753 A52EA537.

RSNA Key Data: CTS Version = 2.

RSNA Key Data: RSN IE:

Ciphers = gcm-encrypt.

Apr 27 11:30:04.678 CEST: CTS SAP ev (Gi1/1/1): EAPOL-Key message #1 parsed and validated.

Apr 27 11:30:04.678 CEST: cts_sap_generate_pmkid_and_sci CTS SAP ev (Gi1/1/1) auth:1833.9dbf.8389 supp:2c3e.cfa9.5199, 07DC55EAB56FE46CEF2AF58A3439A3923343C28EF10C44D5B1C377DCDFDF517F

Apr 27 11:30:04.678 CEST: %CTS-3-SAP_MANUAL_PMKID_MISMATCH: PMKID Mismatch on int(Gi1/1/1), received: 10A08357 BD691C46 DFA82753 A52EA537, expected: 12A6F565 89343155 8E7C6ED3 C3548A30

C3850#

Apr 27 11:30:04.678 CEST: CTS SAP ev (Gi1/1/1): Old state: [waiting to receive message #1],

event: [received message #1], action: [program message #1] failed.

C3850#

peterwinkler1 · ‎01-22-2019

Does anybody get a solutions ?

Thanks