11-15-2012 11:52 AM - edited 03-10-2019 07:47 PM
I've got a strange situation where our ACS seems to be disconnecting network devices periodically. Some of the logs make me thinking there's an issue w/ our AD setup, others point to runtime issues w/ in the ACS. Typically its just a quick drop and the other ACS picks up the load, but it seems to be happening more often.
Anyone have any idea where I should start on this one?
Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[239] [daemon]: cdp_parse_version(): version = Linux 2.6.18-194.26.1.el5PAE #1 SMP Fri Oct 29 14:28:58 EDT 2010 CCM:8.6.1.20000-1
Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[849] [daemon]: parse_cdp_packet(): get CDP_PLATFORM_TYPE
Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[263] [daemon]: cdp_parse_platform(): platform = VMware
Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[919] [daemon]: parse_cdp_packet(): ready to add cdpCache record
Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[927] [daemon]: parse_cdp_packet(): done adding cdpCache record
Nov 15 14:06:25 acs01 debugd[2572]: [2959]: cdp:infra: ether-write.c[87] [daemon]: WriteEther(): wrote len: 201
Nov 15 14:06:25 acs01 debugd[2572]: [2959]: cdp:infra: ether-write.c[112] [daemon]: cdpd write succeed... Writing with retransmissiontime 60... : [2959]: cdp:infra: main.c[128] [daemon]:
Nov 15 14:06:30 acs01 adclient[5099]: WARN <fd:53 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:33 acs01 adclient[5099]: WARN <fd:54 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:43 acs01 adclient[5099]: WARN <fd:43 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:43 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:55 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:56 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:41 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:35 CAPILdapPagedSearch> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:57 acs01 adclient[5099]: WARN <fd:35 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:57 acs01 adclient[5099]: WARN <fd:41 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:58 acs01 adclient[5099]: WARN <fd:51 CAPILdapPagedSearch> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:58 acs01 adclient[5099]: WARN <fd:31 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:58 acs01 adclient[5099]: WARN <fd:22 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:02 acs01 adclient[5099]: WARN <fd:33 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:03 acs01 adclient[5099]: WARN <fd:31 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:07:03 acs01 adclient[5099]: WARN <fd:33 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[762] [daemon]: cdp version: 2
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[763] [daemon]: cdp time-to-live: 180
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[798] [daemon]: aifEntry->cdpInterfaceIfIndex=<2>
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[813] [daemon]: parse_cdp_packet(): cdp info code 256
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[814] [daemon]: parse_cdp_packet(): cdp info length 7424
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[815] [daemon]: parse_cdp_packet(): cdp info bytes left 163
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[828] [daemon]: parse_cdp_packet(): get CDP_DEVICE_ID_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[54] [daemon]: device name= svtcucm.westfieldgrp.corp
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[832] [daemon]: parse_cdp_packet(): get CDP_ADDRESS_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[156] [daemon]: cdp_parse_address(): num_addrs = 1
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[161] [daemon]: cdp_parse_address(): parsing 0 address
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[83] [daemon]: cdp_parse_ip_info(): PT = 1
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[84] [daemon]: cdp_parse_ip_info(): PT length = 1
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[94] [daemon]: cdp_parse_ip_info(): address length = 4
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[99] [daemon]: cdp_parse_ip_info(): got IP address
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[109] [daemon]: cdp_parse_ip_info(): got IP address: 10.10.10.119
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[165] [daemon]: cdp_parse_address(): finished parsing 0 address
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[837] [daemon]: parse_cdp_packet(): get CDP_PORT_ID_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[194] [daemon]: cdp_parse_port_id(): port_name = eth0
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[841] [daemon]: parse_cdp_packet(): get CDP_CAPABILITIES_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[215] [daemon]: cdp_parse_capabilities(): capability = 0x10
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[861] [daemon]: parse_cdp_packet(): get DUPLEX_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[341] [daemon]: cdp_parse_duplex(): is full duplex
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[845] [daemon]: parse_cdp_packet(): get CDP_VERSION_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[239] [daemon]: cdp_parse_version(): version = Linux 2.6.18-194.26.1.el5PAE #1 SMP Fri Oct 29 14:28:58 EDT 2010 CCM:8.6.1.20000-1
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[849] [daemon]: parse_cdp_packet(): get CDP_PLATFORM_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[263] [daemon]: cdp_parse_platform(): platform = VMware
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[919] [daemon]: parse_cdp_packet(): ready to add cdpCache record
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[927] [daemon]: parse_cdp_packet(): done adding cdpCache record
Nov 15 14:07:06 acs01 adclient[5099]: WARN <fd:40 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:07:18 acs01 adclient[5099]: WARN <fd:31 rt_daemon(16882)> Failure while reading message: Incorrect data type
Nov 15 14:07:18 acs01 adclient[5099]: WARN <fd:54 CAPILdapPagedSearch> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:18 acs01 adclient[5099]: WARN <fd:29 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:18 acs01 adclient[5099]: WARN <fd:47 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:25 acs01 debugd[2572]: [2959]: cdp:infra: ether-write.c[87] [daemon]: WriteEther(): wrote len: 201
Nov 15 14:07:25 acs01 debugd[2572]: [2959]: cdp:infra: ether-write.c[112] [daemon]: cdpd write succeed... Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[239] [daemon]: cdp_parse_version(): version = Linux 2.6.18-194.26.1.el5PAE #1 SMP Fri Oct 29 14:28:58 EDT 2010 CCM:8.6.1.20000-1
Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[849] [daemon]: parse_cdp_packet(): get CDP_PLATFORM_TYPE
Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[263] [daemon]: cdp_parse_platform(): platform = VMware
Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[919] [daemon]: parse_cdp_packet(): ready to add cdpCache record
Nov 15 14:06:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[927] [daemon]: parse_cdp_packet(): done adding cdpCache record
Nov 15 14:06:25 acs01 debugd[2572]: [2959]: cdp:infra: ether-write.c[87] [daemon]: WriteEther(): wrote len: 201
Nov 15 14:06:25 acs01 debugd[2572]: [2959]: cdp:infra: ether-write.c[112] [daemon]: cdpd write succeed... Writing with retransmissiontime 60... : [2959]: cdp:infra: main.c[128] [daemon]:
Nov 15 14:06:30 acs01 adclient[5099]: WARN <fd:53 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:33 acs01 adclient[5099]: WARN <fd:54 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:43 acs01 adclient[5099]: WARN <fd:43 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:43 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:55 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:56 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:41 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:54 acs01 adclient[5099]: WARN <fd:35 CAPILdapPagedSearch> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:57 acs01 adclient[5099]: WARN <fd:35 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:57 acs01 adclient[5099]: WARN <fd:41 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:06:58 acs01 adclient[5099]: WARN <fd:51 CAPILdapPagedSearch> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:58 acs01 adclient[5099]: WARN <fd:31 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:06:58 acs01 adclient[5099]: WARN <fd:22 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:02 acs01 adclient[5099]: WARN <fd:33 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:03 acs01 adclient[5099]: WARN <fd:31 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:07:03 acs01 adclient[5099]: WARN <fd:33 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[762] [daemon]: cdp version: 2
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[763] [daemon]: cdp time-to-live: 180
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[798] [daemon]: aifEntry->cdpInterfaceIfIndex=<2>
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[813] [daemon]: parse_cdp_packet(): cdp info code 256
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[814] [daemon]: parse_cdp_packet(): cdp info length 7424
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[815] [daemon]: parse_cdp_packet(): cdp info bytes left 163
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[828] [daemon]: parse_cdp_packet(): get CDP_DEVICE_ID_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[54] [daemon]: device name= svtcucm.westfieldgrp.corp
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[832] [daemon]: parse_cdp_packet(): get CDP_ADDRESS_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[156] [daemon]: cdp_parse_address(): num_addrs = 1
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[161] [daemon]: cdp_parse_address(): parsing 0 address
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[83] [daemon]: cdp_parse_ip_info(): PT = 1
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[84] [daemon]: cdp_parse_ip_info(): PT length = 1
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[94] [daemon]: cdp_parse_ip_info(): address length = 4
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[99] [daemon]: cdp_parse_ip_info(): got IP address
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[109] [daemon]: cdp_parse_ip_info(): got IP address: 10.10.10.119
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[165] [daemon]: cdp_parse_address(): finished parsing 0 address
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[837] [daemon]: parse_cdp_packet(): get CDP_PORT_ID_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[194] [daemon]: cdp_parse_port_id(): port_name = eth0
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[841] [daemon]: parse_cdp_packet(): get CDP_CAPABILITIES_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[215] [daemon]: cdp_parse_capabilities(): capability = 0x10
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[861] [daemon]: parse_cdp_packet(): get DUPLEX_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[341] [daemon]: cdp_parse_duplex(): is full duplex
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[845] [daemon]: parse_cdp_packet(): get CDP_VERSION_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[239] [daemon]: cdp_parse_version(): version = Linux 2.6.18-194.26.1.el5PAE #1 SMP Fri Oct 29 14:28:58 EDT 2010 CCM:8.6.1.20000-1
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[849] [daemon]: parse_cdp_packet(): get CDP_PLATFORM_TYPE
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[263] [daemon]: cdp_parse_platform(): platform = VMware
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[919] [daemon]: parse_cdp_packet(): ready to add cdpCache record
Nov 15 14:07:04 acs01 debugd[2572]: [2959]: cdp:infra: cdp-parse.c[927] [daemon]: parse_cdp_packet(): done adding cdpCache record
Nov 15 14:07:06 acs01 adclient[5099]: WARN <fd:40 rt_daemon(16882)> Failed to send message: Timeout during operation
Nov 15 14:07:18 acs01 adclient[5099]: WARN <fd:31 rt_daemon(16882)> Failure while reading message: Incorrect data type
Nov 15 14:07:18 acs01 adclient[5099]: WARN <fd:54 CAPILdapPagedSearch> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:18 acs01 adclient[5099]: WARN <fd:29 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:18 acs01 adclient[5099]: WARN <fd:47 CAPIGetObjectByName> daemon.ipcserver Unable to send reply message to client -- disconnecting client.
Nov 15 14:07:25 acs01 debugd[2572]: [2959]: cdp:infra: ether-write.c[87] [daemon]: WriteEther(): wrote len: 201
Nov 15 14:07:25 acs01 debugd[2572]: [2959]: cdp:infra: ether-write.c[112] [daemon]: cdpd write succeed...
11-15-2012 12:22 PM
Unless you are using the COA feature, which requires and advanced license type on ACS, ACS can not disconnect users, there must be an attribute like the session-timeout attribute. or a port level reauthentication configuration.
Can you please describe your issue a little bit deeper and how you think ACS is the reason.
Also is this for wired or wireless users?
Tarik Admani
*Please rate helpful posts*
11-15-2012 12:31 PM
Tarik,
Thanks for the reply.. I meant to say that the ACS is disconnecting from the Wireless Controller's and Switches randomly.. not the clients.
We often see the Wireless controllers deactivating and reactivating the ACS's randomly throughout the day.
It seems that today this has increased quite a bit.
11-15-2012 01:11 PM
Is this ACS a virtual machine or an appliance. How many users do you estimate are authenticating via radius/tacacs?
Thanks,
Tarik Admani
*Please rate helpful posts*
11-15-2012 01:16 PM
Its a VM running on Windows.. 5.2 patch lvl 7.
Tacacs normaly runs slim,, w/ a large config capture of 200ish devices every 4 hours.
Radius deals with approx 7000 devices.. our reauth is set fairly high.. so the auth levels should be low most of the day except for wireless users.
Today the ACS (pair) handled 60,000 radius requests and 6500 tacacs requests
11-15-2012 02:50 PM
Are you using eap-tls or PEAP, does the box usually drop off when users are jumping back into the network. also for you wireless are you using the default session timers? Check the advanced section in the WLAN configuration to see what this is set to.
Thanks,
Tarik Admani
*Please rate helpful posts*
11-16-2012 05:28 AM
We are using both EAP-TLS (Primarily for the wireless controllers) <-- This is where we saw the ACS timing out more often.. I increased the wireless controller timeout from 2 sec to 5 sec yesterday.. see if that helps.. Not sure if users are actually getting dropped off or not.. What i'm seeing is the controller deactivating and reactivating the ACS radius servers because it wasn't getting a response.
We've often been seeing radius calls taking up to 3-4 seconds.. which we're being told is expected after opening a case.
We are using PEAP for our wired (Primarily switch based radius calls) <-- these rarely get knocked off, but it happens enough to warrant a look, where the switch will identify a radius (acs) as dead in the middle of the day. The dot1x params on these switches are set to 5 seconds, so I'm assuming this is happening when the ACS is getting busy.. But this really shouldn't be happening with the load we are running,, Thats why i'm trying to investigate if there is another issue somewhere.
11-16-2012 07:13 AM
Jacob,
Are you performing the binary check against AD for EAP-TLS users? Take a look at the following guide with respect to authentications per second.
http://www.cisco.com/en/US/docs/net_mgmt/cisco_secure_access_control_system/5.2/migration/guide/Migration_Deploy.html#wp1054828
Typically the NAD (WLC or switch) will mark a server dead after a threshold (which you address by extending the timeout for the radius server), it seems with the metrics you provided that you may need to consider reviewing your busiest time, and your wireless session timers as a whole. Make a decision to see if the both ACS can handle the amount of work that is presented at the busiest intervals.
Thanks,
Tarik Admani
Sent from Cisco Technical Support iPad App
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