Rachel,
As a first step, try using s_client to connect to a TLS service and
$ openssl s_client -connect <hostname>:<port> -showcerts
There are more possible options on s_client to debug more deeply but
this is a good start.
--Paul
In answer to the above. Testing against three "random" servers (see
bottom of the email for full exchange, top three are through VPN, rest
I wanted to follow up on this.
I updated the servers that create the iked VPN to the 12/5 snapshot the other day.
I then took one machine on the "remote" net and ran openssl s_server.
I had another machine on the "local" net try to connect with openssl s_client.
So, the s_client shows:
SSL_connect:before/connect initialization
SSL_connect:SSLv3 write client hello A
... and nothing more.
The s_server shows:
Using auto DH parameters
Using default temp ECDH parameters
ACCEPT
SSL_accept:before/accept initialization
... and nothing more.
I also had tcpdump running at several places along the route.
On the outgoing/sending interface of the "s_client" machine I see:
21:19:54.735257 172.30.1.254.44715 > 172.30.7.205.443: S 950714671:950714671(0) win 16384 <mss 1460,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 523073824 0> (DF)
21:19:54.773320 172.30.7.205.443 > 172.30.1.254.44715: S 668125506:668125506(0) ack 950714672 win 16384 <mss 1300,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 590367976 523073824>
21:19:54.773391 172.30.1.254.44715 > 172.30.7.205.443: . ack 1 win 256 <nop,nop,timestamp 523073824 590367976> (DF)
21:19:54.774143 172.30.1.254.44715 > 172.30.7.205.443: P 1:197(196) ack 1 win 256 <nop,nop,timestamp 523073824 590367976> (DF)
21:19:56.272544 172.30.1.254.44715 > 172.30.7.205.443: P 1:197(196) ack 1 win 256 <nop,nop,timestamp 523073827 590367976> (DF)
21:19:59.272615 172.30.1.254.44715 > 172.30.7.205.443: P 1:197(196) ack 1 win 256 <nop,nop,timestamp 523073833 590367976> (DF)
21:20:05.272786 172.30.1.254.44715 > 172.30.7.205.443: P 1:197(196) ack 1 win 256 <nop,nop,timestamp 523073845 590367976>
21:20:10.743468 172.30.1.254.44715 > 172.30.7.205.443: F 197:197(0) ack 1 win 256 <nop,nop,timestamp 523073856 590367976>
21:20:10.781912 172.30.7.205.443 > 172.30.1.254.44715: . ack 1 win 261 <nop,nop,timestamp 590368008 523073824,nop,nop,sack 1 {197:197} >
21:20:12.124726 172.30.7.205.443 > 172.30.1.254.44715: F 1:1(0) ack 1 win 261 <nop,nop,timestamp 590368011 523073824>
21:20:12.124786 172.30.1.254.44715 > 172.30.7.205.443: F 197:197(0) ack 2 win 256 <nop,nop,timestamp 523073858 590368011>
21:20:12.162326 172.30.7.205.443 > 172.30.1.254.44715: . ack 1 win 261 <nop,nop,timestamp 590368011 523073824>
21:20:17.273069 172.30.1.254.44715 > 172.30.7.205.443: FP 1:197(196) ack 2 win 256 <nop,nop,timestamp 523073869 590368011> (DF)
On the incoming/receiving interface of the "local" iked machine I see:
21:19:54.737490 172.30.1.254.44715 > 172.30.7.205.443: S 950714671:950714671(0) win 16384 <mss 1460,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 523073824 0> (DF)
21:19:54.775299 172.30.7.205.443 > 172.30.1.254.44715: S 668125506:668125506(0) ack 950714672 win 16384 <mss 1300,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 590367976 523073824>
21:19:54.775625 172.30.1.254.44715 > 172.30.7.205.443: . ack 1 win 256 <nop,nop,timestamp 523073824 590367976> (DF)
21:19:54.776378 172.30.1.254.44715 > 172.30.7.205.443: P 1:197(196) ack 1 win 256 <nop,nop,timestamp 523073824 590367976> (DF)
21:19:56.274790 172.30.1.254.44715 > 172.30.7.205.443: P 1:197(196) ack 1 win 256 <nop,nop,timestamp 523073827 590367976> (DF)
21:19:59.274859 172.30.1.254.44715 > 172.30.7.205.443: P 1:197(196) ack 1 win 256 <nop,nop,timestamp 523073833 590367976> (DF)
21:20:05.275017 172.30.1.254.44715 > 172.30.7.205.443: P 1:197(196) ack 1 win 256 <nop,nop,timestamp 523073845 590367976>
21:20:10.745731 172.30.1.254.44715 > 172.30.7.205.443: F 197:197(0) ack 1 win 256 <nop,nop,timestamp 523073856 590367976>
21:20:10.783860 172.30.7.205.443 > 172.30.1.254.44715: . ack 1 win 261 <nop,nop,timestamp 590368008 523073824,nop,nop,sack 1 {197:197} >
21:20:12.126709 172.30.7.205.443 > 172.30.1.254.44715: F 1:1(0) ack 1 win 261 <nop,nop,timestamp 590368011 523073824>
21:20:12.127041 172.30.1.254.44715 > 172.30.7.205.443: F 197:197(0) ack 2 win 256 <nop,nop,timestamp 523073858 590368011>
21:20:12.164312 172.30.7.205.443 > 172.30.1.254.44715: . ack 1 win 261 <nop,nop,timestamp 590368011 523073824>
But, on the outgoing/sending interface of the "remote" iked machine, all that I see is:
21:19:54.733973 172.30.1.254.44715 > 172.30.7.205.443: S 4173630539:4173630539(0) win 16384 <mss 1300,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 523073824 0>
21:19:54.734355 172.30.7.205.443 > 172.30.1.254.44715: S 2645985599:2645985599(0) ack 4173630540 win 16384 <mss 1300,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 590367976 523073824>
21:19:54.773048 172.30.1.254.44715 > 172.30.7.205.443: . ack 1 win 256 <nop,nop,timestamp 523073824 590367976>
21:20:10.742843 172.30.1.254.44715 > 172.30.7.205.443: F 197:197(0) ack 1 win 256 <nop,nop,timestamp 523073856 590367976>
21:20:10.743111 172.30.7.205.443 > 172.30.1.254.44715: . ack 1 win 261 <nop,nop,timestamp 590368008 523073824,nop,nop,sack 1 {197:197} >
21:20:12.085788 172.30.7.205.443 > 172.30.1.254.44715: F 1:1(0) ack 1 win 261 <nop,nop,timestamp 590368011 523073824>
21:20:12.123252 172.30.1.254.44715 > 172.30.7.205.443: F 197:197(0) ack 2 win 256 <nop,nop,timestamp 523073858 590368011>
21:20:12.123472 172.30.7.205.443 > 172.30.1.254.44715: . ack 1 win 261 <nop,nop,timestamp 590368011 523073824>
And that is all that gets delivered to the incoming/receiving interface of the "s_server" machine:
21:19:54.710031 172.30.1.254.44715 > 172.30.7.205.443: S 4173630539:4173630539(0) win 16384 <mss 1300,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 523073824 0>
21:19:54.710134 172.30.7.205.443 > 172.30.1.254.44715: S 2645985599:2645985599(0) ack 4173630540 win 16384 <mss 1300,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 590367976 523073824>
21:19:54.749110 172.30.1.254.44715 > 172.30.7.205.443: . ack 1 win 256 <nop,nop,timestamp 523073824 590367976>
21:20:10.718972 172.30.1.254.44715 > 172.30.7.205.443: F 197:197(0) ack 1 win 256 <nop,nop,timestamp 523073856 590367976>
21:20:10.719023 172.30.7.205.443 > 172.30.1.254.44715: . ack 1 win 261 <nop,nop,timestamp 590368008 523073824,nop,nop,sack 1 {197:197} >
21:20:12.061678 172.30.7.205.443 > 172.30.1.254.44715: F 1:1(0) ack 1 win 261 <nop,nop,timestamp 590368011 523073824>
21:20:12.099433 172.30.1.254.44715 > 172.30.7.205.443: F 197:197(0) ack 2 win 256 <nop,nop,timestamp 523073858 590368011>
21:20:12.099484 172.30.7.205.443 > 172.30.1.254.44715: . ack 1 win 261 <nop,nop,timestamp 590368011 523073824>
Now, if I try connecting using s_client ON the "remote" iked machine (so, a connection that does not include the iked tunnel), everything works, and tcpdump shows ("the expected?") data and traffic leaving:
21:36:56.027413 172.30.7.1.33610 > 172.30.7.205.443: S 2112686897:2112686897(0) win 16384 <mss 1460,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 3723402680 0> (DF)
21:36:56.027768 172.30.7.205.443 > 172.30.7.1.33610: S 3448062619:3448062619(0) ack 2112686898 win 16384 <mss 1300,nop,nop,sackOK,nop,wscale 6,nop,nop,timestamp 3091368224 3723402680>
21:36:56.027817 172.30.7.1.33610 > 172.30.7.205.443: . ack 1 win 256 <nop,nop,timestamp 3723402680 3091368224> (DF)
21:36:56.028403 172.30.7.1.33610 > 172.30.7.205.443: P 1:197(196) ack 1 win 256 <nop,nop,timestamp 3723402680 3091368224> (DF)
21:36:56.046516 172.30.7.205.443 > 172.30.7.1.33610: . 1:1289(1288) ack 197 win 261 <nop,nop,timestamp 3091368224 3723402680>
21:36:56.046518 172.30.7.205.443 > 172.30.7.1.33610: . 1289:2577(1288) ack 197 win 261 <nop,nop,timestamp 3091368224 3723402680>
21:36:56.046519 172.30.7.205.443 > 172.30.7.1.33610: . 2577:3865(1288) ack 197 win 261 <nop,nop,timestamp 3091368224 3723402680>
21:36:56.046520 172.30.7.205.443 > 172.30.7.1.33610: P 3865:4097(232) ack 197 win 261 <nop,nop,timestamp 3091368224 3723402680>
21:36:56.046607 172.30.7.1.33610 > 172.30.7.205.443: . ack 2577 win 215 <nop,nop,timestamp 3723402680 3091368224> (DF)
21:36:56.046793 172.30.7.1.33610 > 172.30.7.205.443: . ack 4097 win 192 <nop,nop,timestamp 3723402680 3091368224> (DF)
21:36:56.047147 172.30.7.205.443 > 172.30.7.1.33610: P 4097:4473(376) ack 197 win 261 <nop,nop,timestamp 3091368224 3723402680>
21:36:56.047196 172.30.7.1.33610 > 172.30.7.205.443: . ack 4473 win 246 <nop,nop,timestamp 3723402680 3091368224> (DF)
21:36:56.053509 172.30.7.1.33610 > 172.30.7.205.443: P 197:315(118) ack 4473 win 256 <nop,nop,timestamp 3723402680 3091368224> (DF)
21:36:56.055675 172.30.7.205.443 > 172.30.7.1.33610: P 4473:4691(218) ack 315 win 261 <nop,nop,timestamp 3091368224 3723402680>
21:36:56.250855 172.30.7.1.33610 > 172.30.7.205.443: . ack 4691 win 256 <nop,nop,timestamp 3723402681 3091368224> (DF)
21:36:58.540398 172.30.7.1.33610 > 172.30.7.205.443: F 315:315(0) ack 4691 win 256 <nop,nop,timestamp 3723402685 3091368224> (DF)
21:36:58.540581 172.30.7.205.443 > 172.30.7.1.33610: . ack 316 win 261 <nop,nop,timestamp 3091368229 3723402685>
21:36:58.541186 172.30.7.205.443 > 172.30.7.1.33610: F 4691:4691(0) ack 316 win 261 <nop,nop,timestamp 3091368229 3723402685>
21:36:58.541219 172.30.7.1.33610 > 172.30.7.205.443: . ack 4692 win 256 <nop,nop,timestamp 3723402685 3091368229> (DF)
I am no expert, but I can see that this "local" connection sends a lot more data.
So, today I was going to try this again, now looking at physical interfaces and the enc0 interface on the iked endpoints.
But, for whatever reason, I did not have to, because this morning https was working without a problem over the iked VPN.
Unfortunately, I noticed that there was problem with icinga2 (which monitors the hosts on the "remote" net). I noticed that even though the hosts were up, icinga2 was reporting them as down.
I found that on the (alternately) remote or local iked host, icinga connections (over port 5665) were being blocked even though there is a specific "pass rule" in pf.conf to permit them.
For example, in the log I see:
Dec 8 15:50:01 ... pf: Dec 08 15:48:49.346816 rule 4/(match) block out on em0: 172.30.7.205.22112 > 172.30.2.99.5665: R 3963276584:3963276584(0) ack 252894831 win 0
But, pfctl is running with following:
# pfctl -s rules
match in all scrub (no-df random-id max-mss 1300)
pass in quick on em1 all flags S/SA
pass out quick on em1 all flags S/SA
block drop in log on em0 all
block drop out log on em0 all
...
pass quick inet proto tcp from 172.30.7.205 to 172.30.2.99 port = 5665 flags S/SA
... and on.
There are no other "quick" rules between the default block and the quick pass rule that should allow the packet.
I don't understand why the packet is blocked when it should specifically (and "quickly") be passed.
I played with my pf.conf for a while, and, all of a sudden, icinga was able to connect. I undid my changes (things like removing the default block rules) and it continued to work.
I decided to reboot several of the hosts to see if things would be stable. But, they are not.
I now find I can no longer connect to with TLS/SSL over the iked tunnel (the original behavior that seemed to have corrected itself). Also, icinga continues to be unable to verify the status of the remote hosts over port 5665.
I don't have time right now to try using s_client and s_server and watching enc0 to see what is happening, but I will when I can.
If anyone has an ideas on what may be happening, please let me know.
Thanks
Ted