11-17-2012 09:16 AM - edited 07-03-2021 11:04 PM
Dear all,
we are facing some problem to deploy a virtualized localization solution made of WLC, Prime Infrastructure and MSE.
We constructed, in our lab, on a UCS C220M3 with VMWare 5.1 the following solution:
WLC is working properly, can register APs and is properly integrated with the Prime. For the localization solution we deployed three access points:
-one 3502 in flex connect mode
-two 1142 in monitor mode
The problem came out when we started to work with the MSE. MSE has been registered inside Prime and synchronized with maps and controller.
After that we checked the maps but no information was displayed. So we started facing the problem and we found that the NMSP protocol remained inactive even if the troubleshooting windows didn't report any explicit issue.
At this stage we started checking the debug messages and in particular, for the NMSP we countinuously received the follwing message:
*nmspRxServerTask: Nov 17 17:55:09.777: Allocated new NMSP connection 0
*nmspRxServerTask: Nov 17 17:55:09.778: sslConnectionInit: SSL_new() conn ssl 0x2aaaae71ab88
*nmspRxServerTask: Nov 17 17:55:09.778: sslConnectionInit: SSL_do_handshake for conn ssl 0x2aaaae71ab88, conn state: INIT, SSL state: HANDSHAKING
*nmspRxServerTask: Nov 17 17:55:09.778: -- returns WANT_READ for conn ssl 0x2aaaae71ab88
*nmspRxServerTask: Nov 17 17:55:09.778: sslConnectionInit() success with Connection state: INIT, SSL state: HANDSHAKING
*nmspRxServerTask: Nov 17 17:55:09.785: doSSLRecvLoop: Handshake has not completed for conn 0
*nmspRxServerTask: Nov 17 17:55:09.785: sslConnectionInit: SSL_do_handshake for conn ssl 0x2aaaae71ab88, conn state: INIT, SSL state: HANDSHAKING
*nmspRxServerTask: Nov 17 17:55:09.785: -- returns WANT_READ for conn ssl 0x2aaaae71ab88
*nmspRxServerTask: Nov 17 17:55:10.100: doSSLRecvLoop: Handshake has not completed for conn 0
*nmspRxServerTask: Nov 17 17:55:10.100: sslConnectionInit: SSL_do_handshake for conn ssl 0x2aaaae71ab88, conn state: INIT, SSL state: HANDSHAKING
*nmspRxServerTask: Nov 17 17:55:10.100: -- handshake failed for conn ssl 0x2aaaae71ab88,error = error:00000000:lib(0):func(0):reason(0)
*nmspRxServerTask: Nov 17 17:55:10.100: freeing Nmsp conn ssl 0x2aaaae71ab88, conn id 0
Also the statistics for the NMSP protocol emphatized an SSL error:
(Cisco Controller) >show nmsp statistics summary
NMSP Global Counters
Client Measure Send Fail......................... 0
Send RSSI with no entry.......................... 0
APP msg too big.................................. 0
Failed Select on Accept Socket................... 0
Failed SSL write................................. 0
Partial SSL write................................ 0
SSL write returned zero.......................... 0
SSL write attempts to want read.................. 0
SSL write attempts to want write................. 0
SSL write got default error...................... 0
SSL write max data length sent................... 0
SSL write max attempts to write in loop.......... 0
SSL read returned zero........................... 0
SSL read attempts to want read................... 0
SSL read attempts to want write.................. 0
SSL read got default error....................... 0
Failed SSL read - Con Rx buf freed............... 0
Failed SSL read - Con/SSL freed.................. 0
Max records read before exiting SSL read......... 0
--More-- or (q)uit
Highest Prio Tx Q full........................... 0
Normal Prio Tx Q full............................ 0
Highest Prio Tx Q Sent........................... 0
Normal Prio Tx Q Sent............................ 0
Highest Prio Tx Q count.......................... 0
Normal Prio Tx Q count........................... 0
Messages sent by APPs to Highest Prio TxQ........ 0
Max Measure Notify Msg........................... 0
Max Info Notify Msg.............................. 0
Max Highest Prio Tx Q Size....................... 0
Max Normal Prio Tx Q Size........................ 0
Max Rx Size...................................... 1
Max Info Notify Q Size........................... 0
Max Client Info Notify Delay..................... 0
Max Rogue AP Info Notify Delay................... 0
Max Rogue Client Info Notify Delay............... 0
Max Client Measure Notify Delay.................. 0
Max Tag Measure Notify Delay..................... 0
Max Rogue AP Measure Notify Delay................ 0
Max Rogue Client Measure Notify Delay............ 0
Max Client Stats Notify Delay.................... 0
Max RFID Stats Notify Delay...................... 0
RFID Measurement Periodic........................ 0
--More-- or (q)uit
RFID Measurement Immediate....................... 0
SSL Handshake failed............................. 1319
NMSP Rx detected con failure..................... 0
NMSP Tx detected con failure..................... 0
NMSP Tx buf size exceeded........................ 0
NMSP Tx Invalid msg id .......................... 0
Reconnect Before Conn Timeout.................... 0
Rogue AP Info Changed DB Full.................... 0
Rogue AP Meas Changed DB Full.................... 0
Rogue Client Info Changed DB Full................ 0
Rogue Client Meas Changed DB Full................ 0
Looking around the Internet we found a similar case where the issue was solved dealing with the authorization list upon the wireless lan controller but after the suggested check we saw that the MSE is correctly authorized inside the controller: Here's the "show auth-list" on the WLC:
(Cisco Controller) >show auth-list
Authorize MIC APs against AAA ................... disabled
Authorize LSC APs against Auth-List ............. disabled
APs Allowed to Join
AP with Manufacturing Installed Certificate.... no
AP with Self-Signed Certificate................ no
AP with Locally Significant Certificate........ no
Mac Addr Cert Type Key Hash
----------------------- ---------- ------------------------------------------
00:0c:29:68:c8:57 LBS-SSC 6d6703ef9cccfb5a430e04b3ad128f8170fb435c
that perfectly matches what was on the MSE:
cmd> show server-auth-info
invoke command: com.aes.server.cli.CmdGetServerAuthInfo
AesLog queue high mark: 50000
AesLog queue low mark: 500
----------------
Server Auth Info
----------------
MAC Address: 00:0c:29:68:c8:57
Key Hash: 6d6703ef9cccfb5a430e04b3ad128f8170fb435c
Certificate Type: SSC
Finally I tried to look around the MSE logs and here what I found tailing the locserver errors:
==> /opt/mse/logs/locserver/locserver-error-0-0.log <==
11/17/12 17:54:13.513 ERROR[locp] [36] Error in ConnectHandler(endPoint) <LocpSessionTarget mode=CLIENT><LocpEndPoint status=HANDSHAKE totalBytesSent=72000 totalBytesReceived=1315800><LocpEndPoint.Key host=10.0.1.249 port=16113/></LocpEndPoint></LocpSessionTarget>
11/17/12 17:54:13.513 ERROR[com.aes] [36] [ConnectHandler:handle-09] THROW
javax.net.ssl.SSLHandshakeException: General SSLEngine problem
at com.sun.net.ssl.internal.ssl.Handshaker.checkThrown(Handshaker.java:1015)
at com.sun.net.ssl.internal.ssl.SSLEngineImpl.checkTaskThrown(SSLEngineImpl.java:485)
at com.sun.net.ssl.internal.ssl.SSLEngineImpl.writeAppRecord(SSLEngineImpl.java:1128)
at com.sun.net.ssl.internal.ssl.SSLEngineImpl.wrap(SSLEngineImpl.java:1100)
at javax.net.ssl.SSLEngine.wrap(SSLEngine.java:452)
at com.aes.server.locp.transport.IOChannelSecure.doHandshake(IOChannelSecure.java:230)
at com.aes.server.locp.transport.LocpTransportService$ConnectHandler.handle(LocpTransportService.java:354)
at com.aes.server.locp.transport.ChannelEventDispatcherImpl$HandlerTask.run(ChannelEventDispatcherImpl.java:348)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
Caused by: javax.net.ssl.SSLHandshakeException: General SSLEngine problem
at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:174)
at com.sun.net.ssl.internal.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1528)
at com.sun.net.ssl.internal.ssl.Handshaker.fatalSE(Handshaker.java:243)
at com.sun.net.ssl.internal.ssl.Handshaker.fatalSE(Handshaker.java:235)
at com.sun.net.ssl.internal.ssl.ClientHandshaker.serverCertificate(ClientHandshaker.java:1206)
at com.sun.net.ssl.internal.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:136)
at com.sun.net.ssl.internal.ssl.Handshaker.processLoop(Handshaker.java:593)
at com.sun.net.ssl.internal.ssl.Handshaker$1.run(Handshaker.java:533)
at java.security.AccessController.doPrivileged(Native Method)
at com.sun.net.ssl.internal.ssl.Handshaker$DelegatedTask.run(Handshaker.java:952)
at com.aes.server.locp.transport.IOChannelSecure.doTasks(IOChannelSecure.java:265)
at com.aes.server.locp.transport.IOChannelSecure.doHandshake(IOChannelSecure.java:193)
... 8 more
Caused by: sun.security.validator.ValidatorException: No trusted certificate found
at sun.security.validator.SimpleValidator.buildTrustedChain(SimpleValidator.java:346)
at sun.security.validator.SimpleValidator.engineValidate(SimpleValidator.java:111)
at sun.security.validator.Validator.validate(Validator.java:218)
at com.sun.net.ssl.internal.ssl.X509TrustManagerImpl.validate(X509TrustManagerImpl.java:126)
at com.sun.net.ssl.internal.ssl.X509TrustManagerImpl.checkServerTrusted(X509TrustManagerImpl.java:209)
at com.sun.net.ssl.internal.ssl.X509TrustManagerImpl.checkServerTrusted(X509TrustManagerImpl.java:249)
at com.sun.net.ssl.internal.ssl.ClientHandshaker.serverCertificate(ClientHandshaker.java:1185)
... 15 more
Everything seems to bring to a certificate error but I don't know, from a side if this is the right direction of investigfation and, from the other, where to check for this certificate and how to find a solution.
May someone give us some help?
Thank in advance to all.
Regards.
Marco
01-12-2013 02:15 AM
Hi Marco
could you find a solution for that? I'm facing exactly the same issue.
regards
Stefan
01-12-2013 03:01 AM
No Stefan, unfortunatly I wasn't able to find a solution and since it was a demo lab for an expo I stopped to investigate.
Regards.
Marco
01-12-2013 06:12 AM
Same situation here, guess it's a vWLC issue.
It works with my 5500 ...
Thanks for your reply!
Stefan
01-14-2013 07:43 PM
Hi Marco,
I got the same issue as you, my Virtual Prime and Virtual MSE cannot integrate together. How can you integrate without any issue ?
I try to make a new and fresh install on both Prime and MSE but no luck on the integration.
Thanks,
Pongsatorn
01-15-2013 03:23 AM
Hi Pongsatorn,
This is caused by a bug with the ID - CSCub42987. And yes, it only applies to the Virtual WLC's.
Here is the work-around: (need to be performed from the CLI of the MSE as follows)
1. cmdshell
2. config unauthenticated-nmsp true
3. exit
4. service msed restart
Ram.
01-27-2014 02:11 AM
I have the same problem. And after doing follow your guideline, MSE still cannot detect the client.
Here is information from MSE log
The LOCP session target is not responding:
Please help.
Thanks
Toan
09-04-2015 03:25 AM
I had this issue, with hardware 8510 WLC (8.0.110) and virtualised MSE (8.0.110). I have added 3 WLC (same S/W) level and associated with the MSE but only 2 worked, no nmsp shown. Prime showed NMSP as green but when delved into there was no nmsp working. The other 2 WLC were OK (all on same subnet, no ACL / routing issues) I had the same output in the MSE logs as above. In the WLC I did not have the MSE key hash.
In the end I removed the MSE/WLC assignment and re-sync'd, then added the MSE assignment and re-sync'd - this then worked :-)
09-14-2018 08:30 AM
This also came in handy for WLCs and APs that have expired certificates. Had the same issues with the handshake failing (assume due to expired certs). NMSP up but always "inactive" (after years of it working correctly). Disabling NMSP authentication resolved the issue.
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide