Poor application performance through ASA/PAT, early connection termination

[rgnelson]

I am having problem with a particular application, performance is just terrible. This is a JAVA app that runs over 443. I just need another set of eyes on what I'm seeing here. I looks to me that the client application (172.16.x.x) sends the SYN's and the java server (14.67.x.x) sends a FIN to close. The parts throwing me are the RST the Reset-I.  Is this just a mis-behaving application or do I have something else going on here?

%ASA-6-305011: Built dynamic TCP translation from inside:172.16.19.100/52981 to outside:51.51.51.51/52981

%ASA-6-302013: Built outbound TCP connection 47058 for outside:14.67.198.225/443 (14.67.198.225/443) to inside:172.16.19.100/52981 (51.51.51.51/52981)

%ASA-6-305011: Built dynamic TCP translation from inside:172.16.19.100/52983 to outside:51.51.51.51/52983

%ASA-6-302013: Built outbound TCP connection 47059 for outside:14.67.198.225/443 (14.67.198.225/443) to inside:172.16.19.100/52983 (51.51.51.51/52983)

%ASA-6-305011: Built dynamic TCP translation from inside:172.16.19.100/52984 to outside:51.51.51.51/52984

%ASA-6-302013: Built outbound TCP connection 47060 for outside:14.67.198.225/443 (14.67.198.225/443) to inside:172.16.19.100/52984 (51.51.51.51/52984)

%ASA-6-305011: Built dynamic TCP translation from inside:172.16.19.100/52985 to outside:51.51.51.51/52985

%ASA-6-302013: Built outbound TCP connection 47061 for outside:14.67.198.225/443 (14.67.198.225/443) to inside:172.16.19.100/52985 (51.51.51.51/52985)

%ASA-6-305011: Built dynamic TCP translation from inside:172.16.19.100/52986 to outside:51.51.51.51/52986

%ASA-6-302013: Built outbound TCP connection 47062 for outside:14.67.198.225/443 (14.67.198.225/443) to inside:172.16.19.100/52986 (51.51.51.51/52986)

%ASA-6-302014: Teardown TCP connection 47058 for outside:14.67.198.225/443 to inside:172.16.19.100/52981 duration 0:00:00 bytes 9460 TCP FINs

%ASA-6-106015: Deny TCP (no connection) from 14.67.198.225/443 to 51.51.51.51/52981 flags FIN ACK  on interface outside

%ASA-6-305011: Built dynamic TCP translation from inside:172.16.19.100/52987 to outside:51.51.51.51/52987

%ASA-6-302013: Built outbound TCP connection 47063 for outside:14.67.198.225/443 (14.67.198.225/443) to inside:172.16.19.100/52987 (51.51.51.51/52987)

%ASA-6-305011: Built dynamic TCP translation from inside:172.16.2.12/3414 to outside:51.51.51.51/3414

%ASA-6-302013: Built outbound TCP connection 47064 for outside:64.132.151.217/22110 (64.132.151.217/22110) to inside:172.16.2.12/3414 (51.51.51.51/3414)

%ASA-6-302014: Teardown TCP connection 47064 for outside:64.132.151.217/22110 to inside:172.16.2.12/3414 duration 0:00:01 bytes 347 TCP FINs

%ASA-6-302014: Teardown TCP connection 47063 for outside:14.67.198.225/443 to inside:172.16.19.100/52987 duration 0:00:09 bytes 1234 TCP FINs

%ASA-6-106015: Deny TCP (no connection) from 14.67.198.225/443 to 51.51.51.51/52987 flags FIN ACK  on interface outside

%ASA-6-302014: Teardown TCP connection 47059 for outside:14.67.198.225/443 to inside:172.16.19.100/52983 duration 0:00:10 bytes 12758 TCP FINs

%ASA-6-106015: Deny TCP (no connection) from 172.16.19.100/52983 to 14.67.198.225/443 flags RST  on interface inside

%ASA-6-302014: Teardown TCP connection 47061 for outside:14.67.198.225/443 to inside:172.16.19.100/52985 duration 0:00:10 bytes 12790 TCP Reset-I

%ASA-6-106015: Deny TCP (no connection) from 172.16.19.100/52985 to 14.67.198.225/443 flags RST  on interface inside

%ASA-6-106015: Deny TCP (no connection) from 14.67.198.225/443 to 51.51.51.51/52985 flags ACK  on interface outside

%ASA-6-302014: Teardown TCP connection 47062 for outside:14.67.198.225/443 to inside:172.16.19.100/52986 duration 0:00:10 bytes 12758 TCP FINs

%ASA-6-106015: Deny TCP (no connection) from 172.16.19.100/52986 to 14.67.198.225/443 flags RST  on interface inside

%ASA-6-302014: Teardown TCP connection 47060 for outside:14.67.198.225/443 to inside:172.16.19.100/52984 duration 0:00:10 bytes 12742 TCP FINs

%ASA-6-106015: Deny TCP (no connection) from 172.16.19.100/52984 to 14.67.198.225/443 flags RST  on interface inside

%ASA-6-305012: Teardown dynamic TCP translation from inside:172.16.19.100/52981 to outside:51.51.51.51/52981 duration 0:00:31

%ASA-6-305012: Teardown dynamic TCP translation from inside:172.16.2.12/3414 to outside:51.51.51.51/3414 duration 0:00:32

%ASA-6-305012: Teardown dynamic TCP translation from inside:172.16.19.100/52987 to outside:51.51.51.51/52987 duration 0:00:40

%ASA-6-305012: Teardown dynamic TCP translation from inside:172.16.19.100/52983 to outside:51.51.51.51/52983 duration 0:00:41

%ASA-6-305012: Teardown dynamic TCP translation from inside:172.16.19.100/52984 to outside:51.51.51.51/52984 duration 0:00:41

%ASA-6-305012: Teardown dynamic TCP translation from inside:172.16.19.100/52985 to outside:51.51.51.51/52985 duration 0:00:41

%ASA-6-305012: Teardown dynamic TCP translation from inside:172.16.19.100/52986 to outside:51.51.51.51/52986 duration 0:00:41

I think this is relavent config in regard to NAT. The network's listed are are the ASA inside, and other networks inside connected to the switch. asa is on 20, the clients are in 21 and 19. The connected switch does layer 3 routing, EIGRP protocol. The ASA is an EIGRP stub and has proper routes to the client networks.

object-group network DEFAULT-PAT

network-object 172.16.21.0 255.255.255.0

network-object 172.16.22.0 255.255.255.0

network-object 172.16.19.0 255.255.255.0

network-object 172.16.20.0 255.255.255.0

nat (inside,outside) after-auto source dynamic DEFAULT-PAT interface

Debugging NAT shows the proper translation happening.

nat: translation - inside:172.16.19.100/52937 to comcast:51.51.51.51/52937 (xp:0x00007fff23a26600, policy:0x00007fff29fda7c0)

ASA 5515-X version 9.1.2a

[Jouni Forss]

Hi,

Seems pretty strange to me also.

It seems like the ASA first sees the hosts terminating the TCP connection normally and even after this there is still TCP FIN or TCP Reset on the ASA for connection that is already terminated.

Could this perhaps mean that the remote host never receives the last TCP ACK for the connection termination from the client and tries to send TCP FIN ACK again? This would atleast explain why the ASA already removes the TCP connection from its connection table but the remote host would still be sending the TCP FIN ACK.

I guess one thing to further troubleshoot this would be to capture the traffic on "outside" and/or "inside" interface to get a clearer picture of what packets are actually seen on each side of the ASA. A direct capture on the single Client computer could also be done.

Naturally doing the capture on the "outside" interface when you are using PAT might be a bit troublesome unless you can only have one internal host use the application at the time when you are taking the capture.

The captures could look something like this

access-list INSIDE-CAP permit ip host 172.16.19.100 host 14.67.198.225

access-list INSIDE-CAP permit ip host 14.67.198.225 host 172.16.19.100

capture INSIDE-CAP type raw-data access-list INSIDE-CAP interface inside buffer 33500000 circular-buffer

access-list OUTSIDE-CAP permit ip host 51.51.51.51 host 14.67.198.225

access-list OUTSIDE-CAP permit ip host 14.67.198.225 host 51.51.51.51

capture OUTSIDE-CAP type raw-data access-list OUTSIDE-CAP interface inside buffer 33500000 circular-buffer

You can then use the following commands to view if anything is captured or view the capture contents on the ASA CLI directly (I suggest copying the capture to an actual PC and opening it with Wireshark)

show capture

show capture INSIDE-CAP

show capture OUTSIDE-CAP

You can use the following command to copy the capture contents to a PC with TFTP

copy /pcap capture:INSIDE-CAP tftp://x.x.x.x/INSIDE-CAP.pcap

copy /pcap capture:OUTSIDE-CAP tftp://x.x.x.x/OUTSIDE-CAP.pcap

You can use the following commnds to remove the captures

no capture INSIDE-CAP

no capture OUTSIDE-CAP

Hope this helps

- Jouni

[rgnelson]

This is the inside view, it looks pretty clean. Maybe a little packet or two loss at the end, but it could also be the application. amiright?

"1","0.000000","172.16.19.100","14.67.198.225","TCP","54828 > https [SYN] Seq=0 Win=8192 Len=0 MSS=1460 WS=8 SACK_PERM=1"

"2","0.072262","14.67.198.225","172.16.19.100","TCP","https > 54828 [SYN, ACK] Seq=0 Ack=1 Win=8192 Len=0 MSS=1380 WS=8 SACK_PERM=1"

"3","0.072461","172.16.19.100","14.67.198.225","TCP","54828 > https [ACK] Seq=1 Ack=1 Win=66048 Len=0"

"4","0.076535","172.16.19.100","14.67.198.225","SSLv2","Client Hello"

LOTS of normal ACk's

"400","1.868272","14.67.198.225","172.16.19.100","TCP","https > 54832 [ACK] Seq=4399 Ack=7957 Win=65024 Len=0"

"401","1.868730","14.67.198.225","172.16.19.100","TCP","https > 54835 [ACK] Seq=4399 Ack=8021 Win=65024 Len=0"

"402","1.870836","14.67.198.225","172.16.19.100","TLSv1","Application Data"

"403","1.870942","14.67.198.225","172.16.19.100","TLSv1","Application Data"

"404","1.871156","172.16.19.100","14.67.198.225","TCP","54835 > https [ACK] Seq=8021 Ack=4729 Win=66048 Len=0"

"405","1.872346","14.67.198.225","172.16.19.100","TLSv1","Application Data"

"406","1.872407","14.67.198.225","172.16.19.100","TLSv1","Application Data"

"407","1.872605","172.16.19.100","14.67.198.225","TCP","54832 > https [ACK] Seq=7957 Ack=4729 Win=66048 Len=0"

"408","1.880051","14.67.198.225","172.16.19.100","TCP","https > 54833 [ACK] Seq=4399 Ack=7941 Win=65024 Len=0"

"409","1.881379","14.67.198.225","172.16.19.100","TLSv1","Application Data"

"410","1.881440","14.67.198.225","172.16.19.100","TLSv1","Application Data"

"411","1.881669","172.16.19.100","14.67.198.225","TCP","54833 > https [ACK] Seq=7941 Ack=4729 Win=66048 Len=0"

"412","1.896210","14.67.198.225","172.16.19.100","TCP","https > 54834 [ACK] Seq=4399 Ack=7925 Win=65024 Len=0"

"413","1.897842","14.67.198.225","172.16.19.100","TLSv1","Application Data"

"414","1.898376","14.67.198.225","172.16.19.100","TLSv1","Application Data"

"415","1.898575","172.16.19.100","14.67.198.225","TCP","54834 > https [ACK] Seq=7925 Ack=4729 Win=66048 Len=0"

"416","10.539203","172.16.19.100","14.67.198.225","TLSv1","Encrypted Alert"

"417","10.539233","172.16.19.100","14.67.198.225","TCP","54836 > https [FIN, ACK] Seq=760 Ack=439 Win=65792 Len=0"

"418","10.539294","172.16.19.100","14.67.198.225","TLSv1","Encrypted Alert"

"419","10.539294","172.16.19.100","14.67.198.225","TCP","54835 > https [FIN, ACK] Seq=8058 Ack=4729 Win=66048 Len=0"

"420","10.539356","172.16.19.100","14.67.198.225","TLSv1","Encrypted Alert"

"421","10.539371","172.16.19.100","14.67.198.225","TCP","54832 > https [FIN, ACK] Seq=7994 Ack=4729 Win=66048 Len=0"

"422","10.539432","172.16.19.100","14.67.198.225","TLSv1","Encrypted Alert"

"423","10.539432","172.16.19.100","14.67.198.225","TCP","54833 > https [FIN, ACK] Seq=7978 Ack=4729 Win=66048 Len=0"

"424","10.539523","172.16.19.100","14.67.198.225","TLSv1","Encrypted Alert"

"425","10.539523","172.16.19.100","14.67.198.225","TCP","54834 > https [FIN, ACK] Seq=7962 Ack=4729 Win=66048 Len=0"

"426","10.626540","14.67.198.225","172.16.19.100","TLSv1","Encrypted Alert"

"427","10.626769","172.16.19.100","14.67.198.225","TCP","54836 > https [RST, ACK] Seq=761 Ack=476 Win=0 Len=0"

"428","10.632750","14.67.198.225","172.16.19.100","TCP","https > 54832 [ACK] Seq=4729 Ack=7995 Win=65024 Len=0"

"429","10.633986","14.67.198.225","172.16.19.100","TLSv1","Encrypted Alert"

"430","10.634169","172.16.19.100","14.67.198.225","TCP","54832 > https [RST, ACK] Seq=7995 Ack=4766 Win=0 Len=0"

"431","10.634215","14.67.198.225","172.16.19.100","TCP","https > 54832 [FIN, ACK] Seq=4766 Ack=7995 Win=65024 Len=0"

"432","10.634337","172.16.19.100","14.67.198.225","TCP","54832 > https [RST] Seq=7995 Win=0 Len=0"

"433","10.634565","14.67.198.225","172.16.19.100","TCP","https > 54835 [ACK] Seq=4729 Ack=8059 Win=65024 Len=0"

"434","10.634764","14.67.198.225","172.16.19.100","TCP","https > 54833 [ACK] Seq=4729 Ack=7979 Win=65024 Len=0"

"435","10.634886","14.67.198.225","172.16.19.100","TLSv1","Encrypted Alert"

"436","10.635023","14.67.198.225","172.16.19.100","TCP","https > 54835 [FIN, ACK] Seq=4766 Ack=8059 Win=65024 Len=0"

"437","10.635084","172.16.19.100","14.67.198.225","TCP","54835 > https [RST, ACK] Seq=8059 Ack=4766 Win=0 Len=0"

"438","10.635176","172.16.19.100","14.67.198.225","TCP","54835 > https [RST] Seq=8059 Win=0 Len=0"

"439","10.635313","14.67.198.225","172.16.19.100","TCP","https > 54834 [ACK] Seq=4729 Ack=7963 Win=65024 Len=0"

"440","10.635481","14.67.198.225","172.16.19.100","TLSv1","Encrypted Alert"

"441","10.635603","14.67.198.225","172.16.19.100","TCP","https > 54833 [FIN, ACK] Seq=4766 Ack=7979 Win=65024 Len=0"

"442","10.635634","172.16.19.100","14.67.198.225","TCP","54833 > https [RST, ACK] Seq=7979 Ack=4766 Win=0 Len=0"

"443","10.635725","14.67.198.225","172.16.19.100","TLSv1","Encrypted Alert"

"444","10.635725","172.16.19.100","14.67.198.225","TCP","54833 > https [RST] Seq=7979 Win=0 Len=0"

"445","10.635847","14.67.198.225","172.16.19.100","TCP","https > 54834 [FIN, ACK] Seq=4766 Ack=7963 Win=65024 Len=0"

"446","10.635862","172.16.19.100","14.67.198.225","TCP","54834 > https [RST, ACK] Seq=7963 Ack=4766 Win=0 Len=0"

"447","10.635954","172.16.19.100","14.67.198.225","TCP","54834 > https [RST] Seq=7963 Win=0 Len=0"