AnyConnect VPN phones can't connect to ASA from AT&T uverse broadband network

[Athonia Cappelli]

We have AnyConnect VPN phones setup to connect to ASA 5510 running 8.4(4) and it uses Active Directory credentials to login. The connection succeeds from external ISP networks including Comcast and smaller independant service providers. However, when any of us on the AT&T uverse service take this same 7965 phone to our home networks it fails to make any connection to the ASA at all. A packet capture on the ASA shows no connection activity from our uverse IP address.

What's more is that we can successfully authenticate the VPN phone connection when using local account logins (e.g. username admin password ******* priv 15) that are entered on the ASA. AT&T says they're not blocking any ports. It's confounding that it works for local login users but not with A/D.

So I guess the question is: What is the initial TCP/UDP handshake comprised of when a Cisco IP phone builds an AnyConnect SSL connection to an ASA and negotiates authentication of A/D credentials? For instance, what are the port numbers used in this handshake?  I couldn't find any diagrams illustrating ths and the RFCs for DTLS didn't seem to have the answer either.

Thanks in advance.

--Athonia

note: We have a TAC case open currently with subject ASA 5510 VPN Edition w/ 250 SSL User- VPN annyconnect for phones. configuration

[Athonia Cappelli]

Hi Folks,

We are still troubleshooting this issue and, after speaking to the author of the URL below he said that he'd run into this with some ISPs in Canada too.

IP Phone VPN basic configuration example - Cisco Support Community

Anyway, we've been struggling with this issue and spent many hours of TAC's time. We ended up putting the ASAs into an HA (Failover) configuration and we are now back to trying to get the VPN phone feature with user/pass authentication working again. Currently the phones show the following in their console.log. After typing my username/password (the same one that works when accessing the Webvpn interface of the ASA) the error message on the phone is just "Authentication Failed"

161: DBG 04:10:31.497336 VPNU: userId:

162: DBG 04:10:31.497917 VPNU: sgCertFilePath:

163: DBG 04:10:31.498522 VPNU: phoneCertFilePath: /flash1/ciptCert/certs/phone.crt

164: DBG 04:10:31.499100 VPNU: phoneKeyFilePath: /flash1/ciptCert/keys/phoneKey.pvtPKCS1

165: DBG 04:10:31.499859 VPNU: url: https://vpn.companyNameHere.com/Webvpn  [URL changed to obfuscate]

166: DBG 04:10:31.500544 VPNU: End pattern found.

167: NOT 04:10:31.505676 EWCLIENT: [.ewcl.c:221]pid = 27 ppid = 1 tid = 65

168: NOT 04:10:31.547143 DHCP: COLDBOOT - wait 6 seconds...

169: ERR 04:10:31.550614 CDP-D: calling installHandlers

170: ERR 04:10:31.551219 CDP-D: calling cdpDrvrInit

171: ERR 04:10:31.552530 ETH_SET_IPV6 call in6_if_brcm_reset

172: ERR 04:10:31.552915 ETH_SET_IPV6 call in6_if_brcm_up

173: ERR 04:10:31.553267 in6_ifattach_linklocal

174: ERR 04:10:31.553299 in6_ifattach_linklocal call in6_update_ifa

175: ERR 04:10:31.553345            routeList NULL

176: ERR 04:10:31.553594 in6_ifattach_linklocal call in6ifa_ifpforlinklocal

177: ERR 04:10:31.553646 nd6_ifattach_linklocal ndpr:plen:64 mask:ffff:ffff:ffff:ffff:: prefix:fe80::0226:cbff:fe3a:fe6f

178: ERR 04:10:31.553711 nd6_ifattach_linklocal return 0

179: ERR 04:10:31.555136 exit in6_if_brcm_up

180: ERR 04:10:31.555428 ETH_SET_IPV6 call in6_if_loopback_up

181: ERR 04:10:31.555712 enter in6_if_loopback_up

182: ERR 04:10:31.556498 in6_ifattach_linklocal

183: ERR 04:10:31.556536 in6_ifattach_linklocal call in6_update_ifa

184: ERR 04:10:31.556685 in6_ifattach_linklocal call in6ifa_ifpforlinklocal

185: ERR 04:10:31.556736 nd6_ifattach_linklocal ndpr:plen:64 mask:ffff:ffff:ffff:ffff:: prefix:fe80:0001::0001

186: ERR 04:10:31.556819 nd6_ifattach_linklocal return 0

187: ERR 04:10:31.556838 exit in6_if_loopback_up

188: ERR 04:10:31.556849 ETH_SET_IPV6 returned from in6_if_loopback_up

189: NOT 04:10:31.559706 CDP-D: NA power detected, max power = 6300 milliwatts

190: NOT 04:10:31.561947 CDP-D: Enable values LLDP:3 CDP:3

191: NOT 04:10:31.563718 CDP-D: cdpSetRepeater 11

192: NOT 04:10:31.569794 CDP-D: cdpSetSwportCfgRemote 7 timer 15

193: NOT 04:10:31.570447 CDP-D: cdpSetSwportCfgRemote setting : Type=0 Cfg=7 portval=7

194: NOT 04:10:31.574788 CDP-D: cdpSetSwportCfgRemote: Value Sent to IOCTL LOCAL[0] 1  1

195: NOT 04:10:31.579415 CDP-D: cdpPhyReCfg SW Type:0 LocalCfg:1  RemoteCfg:7

196: NOT 04:10:31.579978 CDP-D: cdpSetPcportCfgRemote*** 7

197: NOT 04:10:31.584145 CDP-D: cdpSetPcportCfgRemote Value Sent to IOCTL  LOCAL[0] 1

198: NOT 04:10:31.589071 CDP-D: cdpPhyReCfg PC Type:0 LocalCfg:1  RemoteCfg:7

199: NOT 04:10:31.593727 CDP-D: PHY 0 --> 100 MB LINK IS UP

200: NOT 04:10:31.594576 CDP-D: PHY 1 --> LINK IS DOWN

201: NOT 04:10:31.595107 CDP-D: dpCheckLink(): Link Recovery State RPC LINK UP & MATCH CFG 0

202: WRN 04:10:31.595855 CDP-D: PC port down sending to cdpMsgQue

203: NOT 04:10:31.596591 CDP-D: PALS: is DISABLED [0] palsEnable=0

204: NOT 04:10:31.600211 init: Starting /bin/mount

205: NOT 04:10:31.602820 init: /bin/mount started as pid=30

206: NOT 04:10:31.637003 SECD: file sgn verify SUCCESS, hdr 304 byte,

207: NOT 04:10:31.638340 SECD: initCTL: ** phone has CTL file **

208: NOT 04:10:31.643525 SECD: parseHdr(): start of pad ('T' 0x0d) at TLV 15

209: NOT 04:10:31.644126 SECD: parseHdr(): hdr ver 1.2 (knows upto 2.0)

210: NOT 04:10:31.644678 SECD: parseHdr(): skipping 1 trail bytes (pad and/or unknown TLVs)

211: NOT 04:10:31.645451 SECD: tlUpdateFromFile: TL parse to table: CTL_SUCCESS

212: NOT 04:10:31.645989 SECD: tlUpdateFromFile: Updating master TL table

213: NOT 04:10:31.650136 SECD: parseHdr(): start of pad ('T' 0x0d) at TLV 15

214: NOT 04:10:31.650765 SECD: parseHdr(): hdr ver 1.2 (knows upto 2.0)

215: NOT 04:10:31.651294 SECD: parseHdr(): skipping 1 trail bytes (pad and/or unknown TLVs)

216: NOT 04:10:31.654190 SECD: parseHdr(): start of pad ('T' 0x0d) at TLV 15

217: NOT 04:10:31.654784 SECD: parseHdr(): hdr ver 1.2 (knows upto 2.0)

218: NOT 04:10:31.655312 SECD: parseHdr(): skipping 1 trail bytes (pad and/or unknown TLVs)

219: NOT 04:10:31.701561 PAE: SIGIPCFG received...

220: NOT 04:10:31.719829 SECD: file sgn verify SUCCESS, hdr 264 byte,

221: NOT 04:10:31.721111 SECD: initCTL: ** phone has ITL file **

222: NOT 04:10:31.721892 SECD: setSecMode: sec mode set to AUTH (was UNKNOWN)

223: NOT 04:10:31.724802 SECD: clearCapfList: CAPF table cleared

224: NOT 04:10:31.725946 SECD: initCapfClnt: CAPF clnt initialized

225: WRN 04:10:31.728929 SECD: WARN:initEntropy: couldn't get entropy count in dflt rand obj

226: WRN 04:10:31.729545 SECD: WARN:main: error init'ing extended entropy management

227: NOT 04:10:31.734516 SECD: initTVS: Initializing/Starting TVS Proxy

228: NOT 04:10:31.735167 SECD: loadTvsSrvrCfg: Not in EMCC mode.Loading the flash file :/flash0/sec/misc/tvs.conf

229: NOT 04:10:31.737537 SECD: startTvsThread: Creating TVS Proxy thread

230: NOT 04:10:31.740467 SECD: main: starting service...

231: NOT 04:10:31.751657 CDP-D: setVVLANConfig: VVLAN CHANGED --> NEW:4096 OLD:4096 4096

232: NOT 04:10:31.757059 CDP-D: vlan Configured --> New:4096 old:4096 :4096

233: NOT 04:10:31.758484 CDP-D: Sent SIGNINFO & SIGIPCFG

234: NOT 04:10:31.759479 CDP-D: ----lldpProtoInfo[0].enableState 1

235: NOT 04:10:31.760408 CDP-D: Entering Hold/Trigger Mode....Time:7

236: NOT 04:10:31.761320 CDP-D: ----cdpProtoInfo[0].enableState 1

237: NOT 04:10:31.768027 DNS: pid = 31

238: WRN 04:10:31.771924 ESP: espInfoUpdate() dropped

239: ERR 04:10:31.777621 SECD: EROR:sec_md_bytes: B_GenerateRandomBytes failed

240: ERR 04:10:31.778257 SECD: EROR:handleRandReq: error getting rand bytes, needed 16 bytes

241: NOT 04:10:31.781063 EWCLIENT: [.ewconf.c:247]create UUID 1

242: DBG 04:10:31.789973 VPNU: exec of /bin/vpnc

243: NOT 04:10:31.793338 PAE: SIGIPCFG received...

244: NOT 04:10:31.795602 SECD: clpCreateTvsProxySock: Created TVS proxy socket, 7

245: NOT 04:10:31.797619 SECD: clpCreateTvsProxySock: TVS proxy socket bound to path

246: NOT 04:10:31.798484 SECD: clpTvsInit: TVS Proxy setup thread starting, TVS proxy socket : 7

247: NOT 04:10:32.281020 CDP-D: catchipcfg:getdhcpinfo IP:0 domain: chngVal:0

248: NOT 04:10:32.291666 init: Starting /ubin/zrun

249: NOT 04:10:32.294665 init: /ubin/zrun started as pid=7

250: NOT 04:10:32.295429 init: Starting /bin/sleep

251: NOT 04:10:32.298482 init: /bin/sleep started as pid=8

252: DBG 04:10:32.299665 VPNU: State Startup --> AppsUp

253: NOT 04:10:32.327051 zrun: Starting...

254: NOT 04:10:32.328527 zrun: loadCompressedFileandExecute...

255: NOT 04:10:32.340187 CDP-D: catchipcfg:getdhcpinfo IP:0 domain: chngVal:0

256: INF 04:10:35.582024 zrun: execv(/tmp/sunvm.unzip/sunvm.cnu, argv)

257: ERR 04:10:35.886652 JVM: sunvm pausing for umount

258: NOT 04:10:35.890149 CDP-D: catchipcfg:getdhcpinfo IP:0 domain: chngVal:0

259: ERR 04:10:35.896861 EWCLIENT: [.ewconf.c:297]couldn't retrieve file: /tmp/ewclpasswd.conf

260: NOT 04:10:35.910151 CDP-D: catchipcfg:getdhcpinfo IP:0 domain: chngVal:0

261: NOT 04:10:35.930134 CDP-D: catchipcfg:getdhcpinfo IP:0 domain: chngVal:0

262: NOT 04:10:35.950142 CDP-D: catchipcfg:getdhcpinfo IP:0 domain: chngVal:0

263: NOT 04:10:35.970148 CDP-D: catchipcfg:getdhcpinfo IP:0 domain: chngVal:0

264: NOT 04:10:35.971865 CDP-D: cdpGetPortCfg SPANTOPC CFG:11

265: NOT 04:10:35.981328 CDP-D: configSelectVLAN: 1 OP_USE_CDP:2 oper:5(vlanId:10) cdp:5 lldp:4096 admin:4096 mac:a0:cf:5b:d3:b1:8d

266: WRN 04:10:35.981993 CDP-D: Cfg_Wait_EvCdpDoneNextState_XIdle(): cdp 5 & oper 5 

267: NOT 04:10:35.982502 CDP-D: Cfg_Wait_EvCdpDoneNextState_XIdle(): Operational Vvlan:5 Vlan:10 SrcMac:a0:cf:5b:d3:b1:8d

268: NOT 04:10:35.983174 CDP-D: cdpIntrestIdx: OP:2 idx:0 notify:0 oper.idxOfInterest:0

269: NOT 04:10:35.983716 CDP-D: getCdpExtraInfo: OP:2 Cos:0 Trust:0 lldp.idxOfInterest:-1

270: WRN 04:10:35.984286 CDP-D: cdpSetCos T:0 C:0

271: NOT 04:10:35.987715 VPNC: main: Cisco SVC IPPhone Client v1.0 (1.0) - starting...

272: NOT 04:10:35.988268 VPNC: main: uses OpenSSL 0.9.8g 19 Oct 2007

273: NOT 04:10:35.988752 VPNC: main: compression not supported

274: NOT 04:10:35.989276 VPNC: main: tunnel rekey not supported

275: NOT 04:10:35.989786 VPNC: main: set nice() to 20

276: NOT 04:10:35.990324 VPNC: main: changed CPU limit to 20 sec (default 10)

277: NOT 04:10:35.993825 init: Starting /bin/umount

278: NOT 04:10:35.996364 init: /bin/umount started as pid=9

279: DBG 04:10:35.997015 VPNU: SM wakeup - chld=0 tmr=0 io=1 res=0

280: NOT 04:10:35.998250 VPNC: main: vpn is not enabled

281: NOT 04:10:35.998768 VPNC: main: exiting

282: NOT 04:10:35.999248 VPNC: exit_handler: invoked

283: NOT 04:10:36.001803 VPNC: vpnc_tun_cleanup: invoked

284: NOT 04:10:36.002359 VPNC: vpnc_control_stop: vpnc_control not running...

285: NOT 04:10:36.003731 VPNC: exit_handler: exiting...

286: DBG 04:10:36.014335 VPNU: State AppsUp --> AppsUp

287: DBG 04:10:36.015076 VPNU: SM wakeup - chld=0 tmr=0 io=1 res=0

288: DBG 04:10:36.015649 VPNU: State AppsUp --> AppsUp

289: DBG 04:10:36.016452 VPNU: SM wakeup - chld=1 tmr=0 io=0 res=0

290: DBG 04:10:36.017016 VPNU: reaping '/bin/vpnc': status 0

291: DBG 04:10:36.017752 VPNU:    action=0  flags=1014

292: DBG 04:10:36.018287 VPNU: State AppsUp --> AppsUp

293: ERR 04:10:36.019291 init: /bin/umount powerup started

294: NOT 04:10:36.035489 CDP-D: setVVLANConfig: VVLAN CHANGED --> NEW:5 OLD:4096 5

295: NOT 04:10:36.036807 CDP-D: setVVLANConfig: IPV6 VVLAN CHANGED --> NEW:5 OLD:4096

296: ERR 04:10:36.037707 ETH_SET_IPV6 call in6_if_brcm_reset

297: ERR 04:10:36.038028 enter in6_if_brcm_reset

298: ERR 04:10:36.038315 exit in6_if_brcm_reset

299: ERR 04:10:36.038840 ETH_SET_IPV6 call in6_if_brcm_up

300: ERR 04:10:36.039186 ETH_SET_IPV6 call in6_if_loopback_up

301: ERR 04:10:36.039475 ETH_SET_IPV6 returned from in6_if_loopback_up

302: NOT 04:10:36.043770 CDP-D: vlan Configured --> New:10 old:4096 :10

303: ERR 04:10:36.045089 CDP-D: setVLanConfig change in vlan from NO_VID. No action taken

[Javier Portuguez]

Hi Anthonia,

It uses TCP port 443 by default.

What if you try to connect from the same location with the AnyConnect client? Does it work?

Thanks in advance.

Please rate any helpful posts

[Athonia Cappelli]

yes, AnyConnect from laptops in the same location connect fine. I'm using it now in fact.

[Javier Portuguez]

Then it does not sound like a VPN issue. Did you open the TAC case with the VoIP team by any chance?

Thanks.

[Athonia Cappelli]

Yes, it's the Voice team.  So here's some log files from the console logs show what it looks like when there's a succes. The following is a 7962 phone we have working at one staffer's home who is not behind AT&T uverse:

1162: NOT 09:12:25.408813 VPNC: vpnc_create_dns_conf: creating /tmp/vpn_dns.conf

1163: NOT 09:12:25.410644 VPNC: vpnc_create_dns_conf: Domain -> [someExampleDomainHere.edu]

1164: NOT 09:12:25.411318 VPNC: vpnc_create_dns_conf: DNS [0] -> 172.19.18.6

1165: NOT 09:12:25.411867 VPNC: vpnc_create_dns_conf: DNS [1] -> 172.19.18.103

1166: NOT 09:12:25.412936 VPNC: reset_lease_info: values reset

1167: NOT 09:12:25.413508 VPNC: update_lease_info: lease time: 1209600, max conn time: 0

1168: NOT 09:12:25.414047 VPNC: update_lease_info: now: 66, lease end: 1209666, renew: 604866

1169: NOT 09:12:25.414612 VPNC: do_connect: process_connect success

1170: NOT 09:12:25.415127 VPNC: do_connect: not setting dtls session

1171: NOT 09:12:25.415631 VPNC: protocol_handler: connect: do_connect ok, tunnelfd 13

1172: NOT 09:12:25.416141 VPNC: protocol_handler: SSL keepalive 60 sec from cfg (enabled)

1173: NOT 09:12:25.416697 VPNC: protocol_handler: SSL dpd 0 sec from SG (disabled)

1174: WRN 09:12:25.417230 VPNC: protocol_handler: connect: DTLS not negotiated by SG

1175: NOT 09:12:25.417730 VPNC: protocol_handler: vpnc_tun_connect, bringing up n/w

1176: NOT 09:12:25.418242 VPNC: vpnc_tun_connect: bringing up i/f -> tun0

1177: NOT 09:12:25.418942 VPNC: vpnc_tun_connect: MTU       -> 1290

1178: NOT 09:12:25.419542 VPNC: vpnc_tun_connect: IP addr   -> 172.18.249.37

1179: NOT 09:12:25.420211 VPNC: vpnc_tun_connect: netmask   -> 255.255.255.0

1180: NOT 09:12:25.420782 VPNC: vpnc_tun_connect: broadcast -> 172.18.249.255

1181: NOT 09:12:25.421431 VPNC: vpnc_set_dflt_route: adding default gw <172.18.249.1> via i/f

1182: NOT 09:12:25.422143 VPNC: protocol_handler: vpnc_tun_connect ok

1183: NOT 09:12:25.422690 VPNC: set_conn_state: CONN : 1 (TRYING) --> 2 (SUCCESS)

1184: NOT 09:12:25.423214 VPNC: set_conn_state: VPNC : 4 (Connecting) --> 5 (Connected)

1185: NOT 09:12:25.423757 VPNC: vpnc_send_notify: notify type: 3 [Connected]

1186: NOT 09:12:25.424317 VPNC: vpnc_send_notify: notify code: 1 [Ok]

1187: NOT 09:12:25.424825 VPNC: vpnc_send_notify: notify desc: [connect: connected]

1188: NOT 09:12:25.425313 VPNC: vpnc_send_notify: sending signal 28 w/ value 13 to pid 7

1189: NOT 09:12:25.425880 VPNC: vpnc_send_notify: sending signal 28 w/ value 0 to pid 7

1190: NOT 09:12:25.426590 VPNC: protocol_handler: old address:

1191: NOT 09:12:25.427079 VPNC: protocol_handler: new address: 172.18.249.37

[Javier Portuguez]

Athonia,

Please correct me if I am wrong, but you place a packet-capture on the outside interface of the ASA and you do not see any traffic coming in over the outside interface on TCP port 443 from the IP Phones when they use the AT&T uverse service, correct?

Thanks in advance.

Portu.

[Athonia Cappelli]

That's exactly correct. I even tried turning off DTLS incase it was UDP on port 443 being blocked but this didn't help. We have three people with u-verse Sacramento and the same problem is exhibited at all of our homes. Oddly enough, our engineers in Irvine (Orange County, CA) do not have this problem with the u-verse.

[Javier Portuguez]

I see.

If that is the case then the issue does not depend on the ASA, but on the ISP instead.

Have you moved one of the IP phones from the working location to the non-working location? Does it work?

That would be a good way to have AT&T check on their network.

HTH.

Portu.

Please rate any helpful posts

[Athonia Cappelli]

Portu,

yes, phones that work in Comcast cable at a neighbors house, won't work on my uverse. As usual, AT&T doesn't want to deal with this situation at all. I've called it in to their u-verse support staff but I couldn't so much as get my question to engineers who had a remote understanding of topics such as UDP.

I just wish I knew where in their network they are blocking the connection. Is it the HDSL modem, the DSLAM or somewhere in their core.  Anyway, this issue is mute until we can get AT&T to pay attention. If anyone knows a way to get ahold of AT&T network staff who would be willing and able to look at this then please let  me know.

--Athonia

[Javier Portuguez]

Athonia,

At this point I think you should look for any AT&T forum as well, like this one:

AT&T U-verse Community

In case you do not have any further questions, please mark this question as answered and rate any helpful posts.

You may also considerer opening a similar discussion in the VoIP Community.

Portu.

[jbollinger · Accepted solution]

I too have run into this issue and here is a description of what I found.

If you are using Automatic Network Detection the phone first trys to ping the TFTP server which it has learned from DHCP or set manually with the Alternate TFTP server setting.  If the TFTP server is reachable the VPN does not connect and will not allow the user to manually connect.

ATT Uverse uses DHCP option 150 the, the same option that Cisco UC uses to set the TFTP servers, to locate the local home gateway so that the set top boxes can register to it automaticly.  Because of this you should notice that when you have a VPN Phone on that same network and view the network settings the TFTP Server IP address is the IP of your default gatewat (The ATT router).

Because of the way Automatic network detection works in pinging the TFTP server the phone will always think that it is connected to LAN.  The workaround is to manually set the TFTP server on the phone* to the IP address of what the TFTP server would have been if it had leared it from DHCP on your corporate network.  The reason that you need to do this instead of just using a Bogon address is that once the VPN is connected it tryes to register to the address which you specified. 

Please let me know if this resolves your issue as it did in our case. 

*If you dont know how to set the Alternate TFTP setting you must first select the "Alternate TFTP" and hit **#.  This will allow you to change the default no to yes.  Then the setting below named TFTP Server 1 will allow you to manually specify the address.

[Athonia Cappelli]

I knew it had to be something like that. We'll give this a try and I'll write back if it works.  Thank you!!

[Javier Portuguez]

Great solution! Thanks for sharing!! 5 stars!