0
I have a system setup like this -
Internet <--------------> (eno1) Comp A (192.168.151.19)(eth1) <----------> (eth1) Comp B (192.168.151.15)
eno1 and eth1 are bridged. Comp B access the Internet via computer A
Consider Scenario 1:
No firewall rules present on Comp A. This is like a regular end to end TLS connection
A curl request for facebook.com takes has the following logistics -
sudo SSLKEYLOGFILE=/home/test/FINALDEMO/keylog.txt ./sslkeylog.sh curl -S -k -v -w "@curl-format.txt" --tlsv1.2 https://facebook.com
time_namelookup: 0.022945
time_connect: 0.043648
time_appconnect: 0.117821
time_pretransfer: 0.117884
time_redirect: 0.000000
**time_starttransfer: 0.137791** (Imp)
size_download: 0
size_header: 312
----------
**time_total: 0.137868**
Scenario 2:
There are some firewall rules present on Comp A
- Drop all TLS application data packets (TLS handshake and Change Cipher spec are allowed)
- Allow application data packets for a pair of IP addresses when comp A receive a file via rsync from computer B. Process the file and add firewall rules via ipset (The file sent from comp A contains the ipaddress to add to the firewall)
To achieve these two steps, I have bash scripts that do it is automatically. The time taken to transfer a file via rsync is 0.29 seconds on an average and the time taken to process the file and add firewall rules is 0.03 seconds
A curl request for facebook.com takes the following logistics -
time_namelookup: 0.010086
time_connect: 0.024921
time_appconnect: 0.096774
time_pretransfer: 0.096860
time_redirect: 0.000000
**time_starttransfer: 1.851846** (Imp)
size_download: 0
size_header: 312
----------
**time_total: 1.851923**
I am not able to understand the discrepancy in timing information between the scenarios. The time taken to run the scripts in scenario 2 and allow packets for a connection do not add up.
Can someone please suggest better debugging techniques or insight into why this might be happening?
Edit 1: In scenario 2, TLS application packets are dropped via the u32 module. I check the TLS header of the packet using the u32 module and based on that drop the packet.
Edit 2: Packet capture for a curl request to https://yts.ag is here
https://drive.google.com/open?id=0Bz5corUPBatBdXhCZldxUWp6S2c
So, in Scenario 2, you start curl and let it do a DNS lookup, TCP 3-way handshake, and TLS handshake, but then it stalls while your scripts do the rsync file transfer before the HTTP GET is allowed through? Am I understanding this correctly? – Spiff – 2017-02-14T00:59:21.773
Yes. The scripts take ~0.3 secs for the rsync and 0.03 seconds on comp A. So ideally, the discrepancy in the times should not be more than 0.4 seconds – None – 2017-02-14T01:19:44.633
You're probably dealing with TCP retransmit timeouts. Do you have a packet capture? – Spiff – 2017-02-14T01:28:48.253
Yes, I do have a packet capture running as well. Do you think it is the cost of using the modules with iptables to block packets. ? – None – 2017-02-14T01:31:15.870
I was really asking if you could post the .pcap file for analysis. I think that your firewall is dropping (rather than buffering) the TCP segment that contains the HTTP GET, and then when your scripts unblock the TLS app data, it takes a while for TCP on Comp B to realize it needs to retransmit the GET. – Spiff – 2017-02-14T01:35:39.847
I uploaded the pcap files to this link. https://drive.google.com/open?id=0Bz5corUPBatBdXhCZldxUWp6S2c
– None – 2017-02-14T01:40:41.697The pcap files are captures for a single curl request to https://yts.ag using the same format as in the question. The ipaddress for computer A is 192.168.151.19 and the ip address for comp B is 192.168.151.15. The ip address for https://yts.ag is 104.27.314.30
– None – 2017-02-14T01:42:21.533I did analyze a few more links and they are just a few retransmissions. However, I am not sure if that is the only issue – None – 2017-02-14T19:10:44.753
Well, in both traces you posted, I see a 1.67-second gap between the first attempt to send App Data and the first response from the server that actually Acks that first App Data segment. So I suspect your rules are not updating as quickly as you thought. By the way, the capture from Comp A would be more useful if you did it on the "far" (upstream, Internet) side of Comp A, rather than on the side that faces Comp B. When trying to diagnose firewall rule problems, it's nice to see the view from both sides of the firewall. Both of these traces seemed to be from the same side of the firewall. – Spiff – 2017-02-14T23:04:04.690
So, I did some more tests and these were always the results - there would be tcp retransmission after the Server Change cipher spec. Then computer B sends comp A a TCP SYN message then they are a whole group of TCP messages between comp A and comp B. Then there is the Sever TLS application data response. Would you know why this behaviour happens where comp A and comp B communicate for a SYN message. Comp A is only supposed to forward packets by comp B. – None – 2017-02-15T01:47:26.627
See attached screenshot - The cause of the delay is here from frame 45 to frame 102. https://drive.google.com/open?id=0Bz5corUPBatBSTY0Qmg3ZW42M0k
– None – 2017-02-15T01:51:13.897I presumed that TCP session was your script doing an
ssh-protectedrsyncfile transfer. Is it not? – Spiff – 2017-02-15T02:19:02.980No, I used a filter in Wireshark - "tcp and !ssh" for that screenshot and during analysis – None – 2017-02-15T02:29:38.670
Let us continue this discussion in chat.
– Spiff – 2017-02-15T02:36:05.433