Solved: AP not joining 2504 after being joined to a 9800-CL (Join message decode Maximum message size Failed...

Darg · ‎01-20-2020

Hi everyone,

I have a setup consisting in 2 2504 WLCs (8.0.152.0) which are going to be replaced by a pair of virtual 9800-CLs (16.12.1s).

While performing some tests, a couple of 2702i APs joined the 9800-CL, to set them back to the 2504, I went to the High Availability tab on each AP and typed the data for both the primary and secondary 2504 WLCs. Unfortunately those APs are not joining back to the 2504s and now I don´t have SSH access to those APs (wasn´t enabled for the APs on the 9800). The APs are also not trying to join the 9800-CL

Please find below the outputs for debug capwap packet enable, debug capwap errors enable and debug pm pki enable

debug capwap packet enable
*spamApTask1: Jan 20 12:11:48.523: <<<< Start of CAPWAP Packet >>>>
*spamApTask1: Jan 20 12:11:48.524: CAPWAP Control mesg Recd from 10.xx.xxx.155, Port 53298
*spamApTask1: Jan 20 12:11:48.524: HLEN 4, Radio ID 0, WBID 1
*spamApTask1: Jan 20 12:11:48.524: Msg Type : CAPWAP_DISCOVERY_REQUEST
*spamApTask1: Jan 20 12:11:48.524: Msg Length : 204
*spamApTask1: Jan 20 12:11:48.524: Msg SeqNum : 0
*spamApTask1: Jan 20 12:11:48.524:
*spamApTask1: Jan 20 12:11:48.524: Type : CAPWAP_MSGELE_DISCOVERY_TYPE, Length 1
*spamApTask1: Jan 20 12:11:48.524: Discovery Type : CAPWAP_DISCOVERY_TYPE_STATIC_CONFIG
*spamApTask1: Jan 20 12:11:48.524:
*spamApTask1: Jan 20 12:11:48.524: Type : CAPWAP_MSGELE_WTP_BOARD_DATA, Length 62
*spamApTask1: Jan 20 12:11:48.524: Vendor Identifier : 0x00409600
*spamApTask1: Jan 20 12:11:48.524: WTP_SERIAL_NUMBER : AIR-CAP2702E-E-K9
*spamApTask1: Jan 20 12:11:48.524:
*spamApTask1: Jan 20 12:11:48.524: Type : CAPWAP_MSGELE_WTP_DESCRIPTOR, Length 40
*spamApTask1: Jan 20 12:11:48.524: Maximum Radios Supported : 2
*spamApTask1: Jan 20 12:11:48.524: Radios in Use : 2
*spamApTask1: Jan 20 12:11:48.524: Encryption Capabilities : 0x00 0x01
*spamApTask1: Jan 20 12:11:48.524:
*spamApTask1: Jan 20 12:11:48.524: Type : CAPWAP_MSGELE_WTP_FRAME_TUNNEL, Length 1
*spamApTask1: Jan 20 12:11:48.524: WTP Frame Tunnel Mode : NATIVE_FRAME_TUNNEL_MODE
*spamApTask1: Jan 20 12:11:48.524:
*spamApTask1: Jan 20 12:11:48.524: Type : CAPWAP_MSGELE_WTP_MAC_TYPE, Length 1
*spamApTask1: Jan 20 12:11:48.524: WTP Mac Type : SPLIT_MAC
*spamApTask1: Jan 20 12:11:48.524:
*spamApTask1: Jan 20 12:11:48.524: Type : CAPWAP_MSGELE_WTP_NAME, Length 10
*spamApTask1: Jan 20 12:11:48.524: WTP Name : APNAME
*spamApTask1: Jan 20 12:11:48.524:
*spamApTask1: Jan 20 12:11:48.524: Type : CAPWAP_MSGELE_VENDOR_SPECIFIC_PAYLOAD, Length 10
*spamApTask1: Jan 20 12:11:48.524: Vendor Identifier : 0x00409600
*spamApTask1: Jan 20 12:11:48.524:
IE : UNKNOWN IE 207

*spamApTask1: Jan 20 12:11:48.524: IE Length : 4

*spamApTask1: Jan 20 12:11:48.524: Decode routine not available, Printing Hex Dump

*spamApTask1: Jan 20 12:11:48.524: 00000000: 03 00 00 01 ....

*spamApTask1: Jan 20 12:11:48.524:
*spamApTask1: Jan 20 12:11:48.524: Type : CAPWAP_MSGELE_VENDOR_SPECIFIC_PAYLOAD, Length 16
*spamApTask1: Jan 20 12:11:48.524: Vendor Identifier : 0x00409600
*spamApTask1: Jan 20 12:11:48.524:
IE : RAD_NAME_PAYLOAD

*spamApTask1: Jan 20 12:11:48.524: IE Length : 10

*spamApTask1: Jan 20 12:11:48.524: Rad Name :
*spamApTask1: Jan 20 12:11:48.524: APNAME

*spamApTask1: Jan 20 12:11:48.524:
*spamApTask1: Jan 20 12:11:48.524: Type : CAPWAP_MSGELE_VENDOR_SPECIFIC_PAYLOAD, Length 27
*spamApTask1: Jan 20 12:11:48.524: Vendor Identifier : 0x00409600
*spamApTask1: Jan 20 12:11:48.524:
IE : UNKNOWN IE 215

*spamApTask1: Jan 20 12:11:48.524: IE Length : 21

*spamApTask1: Jan 20 12:11:48.524: Decode routine not available, Printing Hex Dump

*spamApTask1: Jan 20 12:11:48.524: 00000000: 04 59 00 11 04 5a 00 00 04 5c 00 00 04 5b 00 00 .Y...Z...\...[..
00000010: 04 5d 00 01 00 .]...

*spamApTask1: Jan 20 12:11:48.524: <<<< End of CAPWAP Packet >>>>
!
!
!
!
!
!
!
!
!
!
!
debug capwap errors enable
*spamApTask1: Jan 20 12:16:36.901: 00:b7:71:xx:xx:xx Unknown vendor-specific message 0x00d7 from AP

*spamApTask1: Jan 20 12:16:36.901: 00:b7:71:xx:xx:xx Failed to validate vendor message element length 00:b7:71:xx:xx:xx

*spamApTask1: Jan 20 12:16:36.902: 00:b7:71:xx:xx:xx Failed to validate vendor specific payload in Join request

*spamApTask1: Jan 20 12:16:36.902: 00:b7:71:xx:xx:xx Failed to decode vendor specific payloads in Join request

*spamApTask1: Jan 20 12:16:36.903: 00:b7:71:xx:xx:xx Join Request Decode Failed: Failed to decode Join request from 10.xx.xxx.155:53298

*spamApTask1: Jan 20 12:16:36.904: 00:b7:71:xx:xx:xx State machine handler: Failed to process msg type = 3 state = 0 from 10.xx.xxx.155:53298

*spamApTask1: Jan 20 12:16:36.905: 00:b7:71:xx:xx:xx Unable to find deleted AP 00:b7:71:xx:xx:xx
*spamApTask1: Jan 20 12:16:37.351: 00:b7:71:xx:xx:xx Unknown vendor-specific message 0x00d7 from AP

*spamApTask1: Jan 20 12:16:37.352: 00:b7:71:xx:xx:xx Failed to validate vendor message element length 00:b7:71:xx:xx:xx

*spamApTask1: Jan 20 12:16:37.352: 00:b7:71:xx:xx:xx Failed to validate vendor specific payload in Join request

*spamApTask1: Jan 20 12:16:37.353: 00:b7:71:xx:xx:xx Failed to decode vendor specific payloads in Join request

*spamApTask1: Jan 20 12:16:37.353: 00:b7:71:xx:xx:xx Join Request Decode Failed: Failed to decode Join request from 10.xx.xxx.155:53298

*spamApTask1: Jan 20 12:16:37.355: 00:b7:71:xx:xx:xx State machine handler: Failed to process msg type = 3 state = 0 from 10.xx.xxx.155:53298

*spamApTask1: Jan 20 12:16:37.355: 00:b7:71:xx:xx:xx Unable to find deleted AP 00:b7:71:xx:xx:xx
*spamApTask1: Jan 20 12:16:37.774: 00:b7:71:xx:xx:xx Unknown vendor-specific message 0x00d7 from AP

*spamApTask1: Jan 20 12:16:37.774: 00:b7:71:xx:xx:xx Failed to validate vendor message element length 00:b7:71:xx:xx:xx

*spamApTask1: Jan 20 12:16:37.775: 00:b7:71:xx:xx:xx Failed to validate vendor specific payload in Join request

*spamApTask1: Jan 20 12:16:37.775: 00:b7:71:xx:xx:xx Failed to decode vendor specific payloads in Join request

*spamApTask1: Jan 20 12:16:37.776: 00:b7:71:xx:xx:xx Join Request Decode Failed: Failed to decode Join request from 10.xx.xxx.155:53298

*spamApTask1: Jan 20 12:16:37.777: 00:b7:71:xx:xx:xx State machine handler: Failed to process msg type = 3 state = 0 from 10.xx.xxx.155:53298

*spamApTask1: Jan 20 12:16:37.778: 00:b7:71:xx:xx:xx Unable to find deleted AP 00:b7:71:xx:xx:xx
*spamApTask1: Jan 20 12:16:38.199: 00:b7:71:xx:xx:xx Unknown vendor-specific message 0x00d7 from AP

*spamApTask1: Jan 20 12:16:38.200: 00:b7:71:xx:xx:xx Failed to validate vendor message element length 00:b7:71:xx:xx:xx

*spamApTask1: Jan 20 12:16:38.200: 00:b7:71:xx:xx:xx Failed to validate vendor specific payload in Join request

*spamApTask1: Jan 20 12:16:38.201: 00:b7:71:xx:xx:xx Failed to decode vendor specific payloads in Join request

*spamApTask1: Jan 20 12:16:38.201: 00:b7:71:xx:xx:xx Join Request Decode Failed: Failed to decode Join request from 10.xx.xxx.155:53298

*spamApTask1: Jan 20 12:16:38.203: 00:b7:71:xx:xx:xx State machine handler: Failed to process msg type = 3 state = 0 from 10.xx.xxx.155:53298

*spamApTask1: Jan 20 12:16:38.204: 00:b7:71:xx:xx:xx Unable to find deleted AP 00:b7:71:xx:xx:xx
*spamApTask1: Jan 20 12:16:38.625: 00:b7:71:xx:xx:xx Unknown vendor-specific message 0x00d7 from AP

*spamApTask1: Jan 20 12:16:38.625: 00:b7:71:xx:xx:xx Failed to validate vendor message element length 00:b7:71:xx:xx:xx

*spamApTask1: Jan 20 12:16:38.625: 00:b7:71:xx:xx:xx Failed to validate vendor specific payload in Join request

*spamApTask1: Jan 20 12:16:38.625: 00:b7:71:xx:xx:xx Failed to decode vendor specific payloads in Join request

*spamApTask1: Jan 20 12:16:38.625: 00:b7:71:xx:xx:xx Join Request Decode Failed: Failed to decode Join request from 10.xx.xxx.155:53298

*spamApTask1: Jan 20 12:16:38.627: 00:b7:71:xx:xx:xx State machine handler: Failed to process msg type = 3 state = 0 from 10.xx.xxx.155:53298
!
!
!
!
!
!
!
!
!
!
!
debug pm pki enable
*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: called to evaluate <cscoSha2IdCert>

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 4, ID cert >bsnSslWebauthCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 3, ID cert >bsnSslWebadminCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 2, ID cert >cscoDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 1, ID cert >bsnDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 0, ID cert >bsnOldDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: failed to find matching cert.

*spamApTask2: Jan 20 13:20:43.954: sshpmGetDERIDCert: Using SHA2 Id cert on WLC

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: called to evaluate <cscoDefaultIdCert>

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 4, ID cert >bsnSslWebauthCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 3, ID cert >bsnSslWebadminCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 2, ID cert >cscoDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCertFromCID: called to get cert for CID 184f5b56

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCertFromCID: comparing to row 4, certname >bsnSslWebauthCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCertFromCID: comparing to row 3, certname >bsnSslWebadminCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCertFromCID: comparing to row 2, certname >cscoDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: called to evaluate <cscoSha2IdCert>

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 4, ID cert >bsnSslWebauthCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 3, ID cert >bsnSslWebadminCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 2, ID cert >cscoDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 1, ID cert >bsnDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 0, ID cert >bsnOldDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: failed to find matching cert.

*spamApTask2: Jan 20 13:20:43.954: sshpmGetDERIDCertPrivateKey: Using SHA2 Id cert Private Keys on WLC

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: called to evaluate <cscoDefaultIdCert>

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 4, ID cert >bsnSslWebauthCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 3, ID cert >bsnSslWebadminCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetCID: comparing to row 2, ID cert >cscoDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetSshPrivateKeyFromCID: called to get key for CID 184f5b56

*spamApTask2: Jan 20 13:20:43.954: sshpmGetSshPrivateKeyFromCID: comparing to row 0, certname >bsnOldDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetSshPrivateKeyFromCID: comparing to row 1, certname >bsnDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetSshPrivateKeyFromCID: comparing to row 2, certname >cscoDefaultIdCert<

*spamApTask2: Jan 20 13:20:43.954: sshpmGetSshPrivateKeyFromCID: match in row 2

*spamApTask2: Jan 20 13:20:44.258: sshpmGetIssuerHandles: locking ca cert table

*spamApTask2: Jan 20 13:20:44.258: sshpmGetIssuerHandles: calling x509_alloc() for user cert

*spamApTask2: Jan 20 13:20:44.258: sshpmGetIssuerHandles: calling x509_decode()

*spamApTask2: Jan 20 13:20:44.261: sshpmGetIssuerHandles: <subject> C=US, ST=California, L=San Jose, O=Cisco Systems, CN=AP3G2-502fa8xxxxxx, MAILTO=support@cisco.com

*spamApTask2: Jan 20 13:20:44.261: sshpmGetIssuerHandles: <issuer> O=Cisco, CN=Cisco Manufacturing CA SHA2

*spamApTask2: Jan 20 13:20:44.261: sshpmGetIssuerHandles: Mac Address in subject is 50:2f:a8:xx:xx:xx

*spamApTask2: Jan 20 13:20:44.261: sshpmGetIssuerHandles: Cert Name in subject is AP3G2-502fa8xxxxxx

*spamApTask2: Jan 20 13:20:44.261: sshpmGetIssuerHandles: Extracted cert issuer from subject name.

*spamApTask2: Jan 20 13:20:44.261: sshpmGetIssuerHandles: Cert is issued by Cisco Systems.

*spamApTask2: Jan 20 13:20:44.261: sshpmGetCID: called to evaluate <cscoDefaultMfgCaCert>

*spamApTask2: Jan 20 13:20:44.261: sshpmGetCID: comparing to row 7, CA cert >cscoMfgSha2CaCert<

*spamApTask2: Jan 20 13:20:44.261: sshpmGetCID: comparing to row 6, CA cert >cscoRootSha2CaCert<

*spamApTask2: Jan 20 13:20:44.261: sshpmGetCID: comparing to row 5, CA cert >cscoDefaultMfgCaCert<

*spamApTask2: Jan 20 13:20:44.261: sshpmGetCertFromCID: called to get cert for CID 20197eee

*spamApTask2: Jan 20 13:20:44.261: sshpmGetCertFromCID: comparing to row 7, certname >cscoMfgSha2CaCert<

*spamApTask2: Jan 20 13:20:44.261: sshpmGetCertFromCID: comparing to row 6, certname >cscoRootSha2CaCert<

*spamApTask2: Jan 20 13:20:44.261: sshpmGetCertFromCID: comparing to row 5, certname >cscoDefaultMfgCaCert<

*spamApTask2: Jan 20 13:20:44.261: ssphmUserCertVerify: calling x509_decode()

*spamApTask2: Jan 20 13:20:44.270: ssphmUserCertVerify: failed to verify AP cert >cscoDefaultMfgCaCert<

*spamApTask2: Jan 20 13:20:44.270: sshpmGetCID: called to evaluate <cscoMfgSha2CaCert>

*spamApTask2: Jan 20 13:20:44.270: sshpmGetCID: comparing to row 7, CA cert >cscoMfgSha2CaCert<

*spamApTask2: Jan 20 13:20:44.270: sshpmGetCertFromCID: called to get cert for CID 2144e524

*spamApTask2: Jan 20 13:20:44.270: sshpmGetCertFromCID: comparing to row 7, certname >cscoMfgSha2CaCert<

*spamApTask2: Jan 20 13:20:44.270: ssphmUserCertVerify: calling x509_decode()

*spamApTask2: Jan 20 13:20:44.305: ssphmUserCertVerify: user cert verfied using >cscoMfgSha2CaCert<

*spamApTask2: Jan 20 13:20:44.305: sshpmGetIssuerHandles: ValidityString (current): 2020/01/20/13:20:44

*spamApTask2: Jan 20 13:20:44.305: sshpmGetIssuerHandles: ValidityString (NotBefore): 2018/08/22/06:53:35

*spamApTask2: Jan 20 13:20:44.305: sshpmGetIssuerHandles: ValidityString (NotAfter): 2037/11/12/13:00:17

*spamApTask2: Jan 20 13:20:44.305: sshpmGetIssuerHandles: Signature Algorithm is rsa-pkcs1-sha256

*spamApTask2: Jan 20 13:20:44.305: sshpmGetIssuerHandles: getting cisco ID cert handle...

*spamApTask2: Jan 20 13:20:44.306: sshpmGetCID: called to evaluate <cscoDefaultIdCert>

*spamApTask2: Jan 20 13:20:44.306: sshpmGetCID: comparing to row 4, ID cert >bsnSslWebauthCert<

*spamApTask2: Jan 20 13:20:44.306: sshpmGetCID: comparing to row 3, ID cert >bsnSslWebadminCert<

*spamApTask2: Jan 20 13:20:44.306: sshpmGetCID: comparing to row 2, ID cert >cscoDefaultIdCert<

*spamApTask2: Jan 20 13:20:44.307: sshpmFreePublicKeyHandle: called with 0x2bf4723c

*spamApTask2: Jan 20 13:20:44.307: sshpmFreePublicKeyHandle: freeing public key

*spamApTask2: Jan 20 13:20:44.410: sshpmGetCID: called to evaluate <cscoSha2IdCert>

*spamApTask2: Jan 20 13:20:44.411: sshpmGetCID: comparing to row 4, ID cert >bsnSslWebauthCert<

*spamApTask2: Jan 20 13:20:44.411: sshpmGetCID: comparing to row 3, ID cert >bsnSslWebadminCert<

*spamApTask2: Jan 20 13:20:44.411: sshpmGetCID: comparing to row 2, ID cert >cscoDefaultIdCert<

*spamApTask2: Jan 20 13:20:44.412: sshpmGetCID: comparing to row 1, ID cert >bsnDefaultIdCert<

*spamApTask2: Jan 20 13:20:44.412: sshpmGetCID: comparing to row 0, ID cert >bsnOldDefaultIdCert<

*spamApTask2: Jan 20 13:20:44.413: sshpmGetCID: failed to find matching cert.

*spamApTask2: Jan 20 13:20:44.413: sshpmGetDERIDCert: Using SHA2 Id cert on WLC

All Aps, WLCs 2504 and vWLCs 9800-CL are on the same VLAN.

Thanks in advance.

Regards

Scott Fella · ‎01-20-2020

You shouldn’t of tested in production to be honest. The 9800 doesn’t support mobility with AireOS unless the code is on 8.8 or 8.9 I believe. What you will have to do is take the 9800 offline and factory reset the ap using the mode button and maybe possibly you will need console. Console is the only way to see what is happening, so since the ap does not join either controller, it’s best to console in and see what is happening before you factory reset or maybe even uploading the recovery image back to the ap.

-Scott
*** Please rate helpful posts ***

View solution in original post

Scott Fella · ‎01-20-2020

You shouldn’t of tested in production to be honest. The 9800 doesn’t support mobility with AireOS unless the code is on 8.8 or 8.9 I believe. What you will have to do is take the 9800 offline and factory reset the ap using the mode button and maybe possibly you will need console. Console is the only way to see what is happening, so since the ap does not join either controller, it’s best to console in and see what is happening before you factory reset or maybe even uploading the recovery image back to the ap.

-Scott
*** Please rate helpful posts ***

Darg · ‎01-20-2020

Thanks for your response Scott,

Reseting the APs with the mode button is what I was trying to avoid, but I´m afraid I have no other option.

Regards

Scott Fella · ‎01-20-2020

There is nothing you can do when the ap doesn’t join. The only hope is to bounce the port a few times and pray that works. If not, console is what you need to have to determine what is happening.

-Scott
*** Please rate helpful posts ***

Wenchao Wu · ‎04-10-2024

If you cannot touch the AP directly and the AP can only be associated with 9800.

You can try to downgrade the ap image to compatible with AireOS use below command on 9800

"ap name <AP-Name> tftp-downgrade <tftp-server-ip-address> <ap image tar file>"

AP not joining 2504 after being joined to a 9800-CL (Join message decode Maximum message size Failed)