CUPS client 7.0(1.13056)
Windows 2003 VPN (PPTP/GRE)
The CUPS client works wonderfully on LAN/WAN, but when using VPN, it logs in and shows status, but LOGON SERVER and LDAP SERVER show unavailable.
When try to start a chat, says 'An Instant Message could not be started because the network appears to be disconnected.'
Interestingly, Presence phone (UPC[username]) and TFTP are green.
Routing works and more, so, the LDAP server is in the same L2 network as the VPN server's interface.
I read through several posts regarding this issue, including:
- validate profile is set to Cisco SIP Proxy TCP Listener (this was under App --> CUPS --> Settings for v7)
- validating our FW does not do SIP inspection (though moot, since our FW isn't the terminating point for the VPN tunnel, so it's all encapsulated through the tunnel)
- acknowledge the known bug/caveat (CSCsf26033) in the CUPSr7 release notes which says to use TCP for the profile.
I even used Wireshark to validate the frames were TCP and the servers are talking and they appear to be!?
Yet, RED for both those servers.
I'm stuck and could use some suggestions.
(Love this site, by the way)
The easiest way to troubleshoot network-suspected issue is to do a packet capture on CUPS server. Here are the steps:
1) SSH to CUPS
2) Type command below
utils network capture file cups count 100000 size all host all 192.168.2.100
substitute 192.168.2.100 with the IP address of the CUPC client
3) Type command below to transfer the file to a SFTP server. If you don't have a SFTP server, download one from www.freeftpd.com.
file get activelog platform/cli/cups.cap
4)Upload the file here and let me know the IP of the CUPS and CUPC.
Wow, thanks, Michael, for the response and information. This is great stuff. I had no idea Cisco made the sniffer functionality available on UCM. Nice!
Attached is the file, per your request.
CUPS is 192.168.202.4 and CUPC is 172.16.103.3 (VPN'd in).
The process I ran:
1. VPNd in
2. SSHd to CUPS
3. Started sniffer
4. Launched CUPC
5. After it loaded, I saw status, then verified the same problem persisted (logon and ldap server unavailable (red)) via server health.
6. CTLR+C on CUPS
Then xferred file over and am uploading it.
I appreciate the assistance and education!
if you span/mirror the switch port on which CUPS is connected to to your PC and run Sniffer or Wireshark you get the same file even much faster...
It is even better to capture the frames on the internal interface of your vpn device because CUPC is also communicating with your DNS server(s) and your LDAP server(s). This communication is not shown on the CUPS because it newer reaches it...
But you can't see into the conversation which is protected by TLS. So you are not able to get information about the login process from CUPC to CUPS.
Question for htluo: Is there a way do disable TLS between CUPS and CUPC for trouble shooting or get a capture behind the TLS process on CUPS ?
alternatively you can capture from the client (wireshark locally) which I did before opening this discussion. i'm baffled because L2/3 connectivity is solid; so IMHO this must be an application issue - something restricting it.
what about this theory:
Per the r7 CUPS release notes, under Table5, SW REQ for CUPC on M$, it has 'Cisco VPN Client SW, r5 of later' for VPN requirement.
Perhaps the r7 CUPC client 'looks' for the VPN client and doesn't let you connect without it?
Again, we're using the Windows VPN client.
You can also enable detail logging in CUPC - help and look into the c:\documents and settings\user name\local settings\apps\cisco\Unified Personal Communicator\logs\UnifiedClientLog4CXX.txt.x
Don't forget to disable detail logging after that.
I enabled detailed logging and this looks interesting:
2009-01-14 11:13:18,214 [0x00000f0c] DEBUG LCDirectory - LDAPDirectoryImpl::SearchThread:RequestQueue has  pending requests
2009-01-14 11:13:18,214 [0x00000f0c] DEBUG LCConnection - LDAP_DB reportResult(DISCONNECTED): reason=UNREACHABLE, functionality=NONE
2009-01-14 11:13:18,214 [0x00000f0c] DEBUG LCConnection - LDAP_DB setReason(): [SUSPENDED] --> [UNREACHABLE]
2009-01-14 11:13:18,214 [0x00000f0c] DEBUG LCConnection - $$$***** LDAP_DB Server 192.168.1.14, State was IDLE, ServerAdapter 0x70008
2009-01-14 11:13:18,214 [0x00000f0c] DEBUG LCConnection - LDAP_DB reportResult(): unexpected result (DISCONNECTED) for state IDLE
2009-01-14 11:13:21,214 [0x00000f0c] DEBUG LCDirectory - LDAPDirectoryImpl::SearchThread:RequestQueue has  pending requests
2009-01-14 11:13:21,214 [0x00000f0c] DEBUG LCConnection - LDAP_DB reportResult(DISCONNECTED): reason=UNREACHABLE, functionality=NONE
But the LDAP server does appear reachable (via ICMP or http or telnet)...any thoughts on this?
Thank you, all, again for your help.
From sniffer capture, presence part worked fine.
Could you do the following?
1) On CUPC > Help, enable detailed logging.
2) Exit CUPC (make sure it's not running in the system stray if you're using CUPC 7.x)
3) Delete all old logs in "%USERPROFILE%\Local Settings\Application Data\Cisco\Unified Personal Communicator\Logs"
4) Run sniffer capture on CUPC client and start capture.
5) Launch CUPC and wait for the problem.
6) Stop sniffer capture.
7) On CUPC > Help > Create problem report
Attached sniffer capture and problem report here. We should be able to tell. :)
Ok, followed the steps and attached are the (a)logs, (b) CUPC wireshark capture, and I am looking for the zipped problem report now...not sure where it saves it...it said it created the problem report successfully, but didn't show up in the 'Cisco' directory under Local Settings...
It looks like we do have some network issue here.
In sniffer capture, things are not right after packet 264 (LDAP unbind).
After packet 264, we should be seeing a "tcp three-way handshake" - SYN, SYN/ACK, ACK.
After the handshake, we should see CUPC initiate another LDAP bindRequest.
In your capture, we only see FIN and FIN/ACK.
You'll need LDAP server packet capture to further investigate. But at this point, we're pretty sure it's network related.
Nice! yes, I see the unbind now in 264 and the FIN/ACK in 266. I'll try to generate a capture on the LDAP server next.
Attached is the CUPC (from the desktop!)
another lead perhaps?
I captured the same data (on the CUPC client) while connected to the LAN (when everything is working) and stripped out the same requests to the same server (.1.14).
the observation here is this:
1. bindRequest(1) completes at frame 7
2. unbindRequest(2) starts at frame 8
3. we observe FIN/ACK, etc and then
4. DNS requests for CUPS at frame 13
5. These carry 10 frames until frame 22
6. Then in Frame23, we see the new SYN to setup bindRequest(3)
In the 'non-working' (while I am VPNd in) we observe the same steps 1-5, but then
6. a DNS request not in the working capture appears in frame 21.
7. all frames 21 - 26 are not present in the working capture
And then there is the missing Bind(3) that you are referring to.
So my hunting trail right now is trying to isolate why those extra DNS requests are made. Why does the client need to make those while VPN'd in but not while connected to the LAN?
Those "extra" DNS query were for LDAP:
Packet # 23
When the PC was in LAN, I think those already got populated into DNS cache during DHCP or logon process. Hence the LAN PC didn't have to query it again.
ah, gotcha...that would make sense...you are still thinking 'network related' though? the same FIN/ACK combination exist in both trace files, it's just the 3rd instance (and new 3-way handshake) is missing...as if 'something failed' like a dependency, so #3 never kicked off...i can certainly communicate with the LDAP servers, so why isn't it 'starting' the 3rd BIND?
Hey, again, I really appreciate the help.