PPP Link Negotiation Never Ends?
michael-hahn opened this issue · 1 comments
michael-hahn commented
Hi,
Thank you for your SSTP server implementation!
As I am not familiar with networking, I am wondering if you can provide some insight on the issues I am having now. I can run the server on my Ubuntu VM without a problem:
sudo+ssh://vagrant@127.0.0.1:2222/usr/bin/python3.6 -u /home/vagrant/host/sstp-server/sstpd/run.py -f ../sstp-server.ini -s site1
2021-07-07 22:54:23,245 INFO: Cert SHA-1: 54dabc04b60dc153cb6cd2a7187484e087da77dc
2021-07-07 22:54:23,245 INFO: Cert SHA-256: 1551aac7c9caf20f974ab7d6c2a67d5fbfdc8cc881b1272f2f15656c2f70040b
2021-07-07 22:54:23,245 INFO: Running without uvloop
2021-07-07 22:54:23,245 DEBUG: Using selector: EpollSelector
2021-07-07 22:54:23,249 INFO: Listening on 192.168.33.10:443...
I am using the following configs:
[site1]
log_level = 5
listen = 192.168.33.10
listen_port = 443
pem_cert = /home/vagrant/host/sstp-server/cert.pem
pem_key = /home/vagrant/host/sstp-server/key.pem
local = 192.168.20.1
remote = 192.168.20.0/24
pppd_config = /etc/ppp/options.sstpd
And the pppd_config file looks like this:
name sstpd
noauth
nologfd
ms-dns 8.8.8.8
ms-dns 8.8.4.4
debug
Then I tried to use sstpc on my host machine to connect to the VPN server:
sstp-server % sudo /usr/local/sbin/sstpc --log-level 5 --log-stderr --cert-warn --user user --password 'password' 192.168.33.10:443 usepeerdns noauth noipdefault defaultroute refuse-eap noccp
Now, the server outputs:
sudo+ssh://vagrant@127.0.0.1:2222/usr/bin/python3.6 -u /home/vagrant/host/sstp-server/sstpd/run.py -f ../sstp-server.ini -s site1
2021-07-07 22:59:42,641 INFO: Cert SHA-1: 54dabc04b60dc153cb6cd2a7187484e087da77dc
2021-07-07 22:59:42,642 INFO: Cert SHA-256: 1551aac7c9caf20f974ab7d6c2a67d5fbfdc8cc881b1272f2f15656c2f70040b
2021-07-07 22:59:42,642 INFO: Running without uvloop
2021-07-07 22:59:42,642 DEBUG: Using selector: EpollSelector
2021-07-07 22:59:42,645 INFO: Listening on 192.168.33.10:443...
2021-07-07 22:59:47,765 INFO: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] SSTP control packet (CALL_CONNECT_REQUEST) received.
2021-07-07 22:59:47,766 INFO: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] Registered address 192.168.20.2
2021-07-07 22:59:47,771 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] Raw data: 7eff7d23c0217d217d217d207d347d227d267d207d207d207d207d257d26e17d2c63d57d277d227d287d22466b7e
2021-07-07 22:59:47,771 DEBUG: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] pppd => sstp (24 bytes)
2021-07-07 22:59:47,771 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] ff03c021010100140206000000000506e10c63d507020802
2021-07-07 22:59:47,772 DEBUG: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] sstp => pppd (24 bytes).
2021-07-07 22:59:47,772 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] ff03c021010100140206000000000506e10c63d507020802
2021-07-07 22:59:47,774 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] Raw data: 7eff7d23c0217d237d217d207d2a7d257d26fa49fbd9c6dd7e
2021-07-07 22:59:47,774 DEBUG: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] pppd => sstp (14 bytes)
2021-07-07 22:59:47,774 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] ff03c0210301000a0506fa49fbd9
2021-07-07 22:59:47,775 DEBUG: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] sstp => pppd (14 bytes).
2021-07-07 22:59:47,776 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] ff03c0210301000a0506fa49fbd9
2021-07-07 22:59:47,777 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] Raw data: 7eff7d23c0217d217d227d207d347d227d267d207d207d207d207d257d265b3189967d277d227d287d22c3597e
2021-07-07 22:59:47,777 DEBUG: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] pppd => sstp (24 bytes)
2021-07-07 22:59:47,777 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] ff03c0210102001402060000000005065b31899607020802
2021-07-07 22:59:47,777 DEBUG: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] sstp => pppd (24 bytes).
2021-07-07 22:59:47,778 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] ff03c0210102001402060000000005065b31899607020802
2021-07-07 22:59:47,778 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] Raw data: 7eff7d23c0217d237d227d207d2a7d257d2684dfc57d2535907e
2021-07-07 22:59:47,778 DEBUG: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] pppd => sstp (14 bytes)
2021-07-07 22:59:47,778 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] ff03c0210302000a050684dfc505
2021-07-07 22:59:47,779 DEBUG: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] sstp => pppd (24 bytes).
2021-07-07 22:59:47,780 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] ff03c0210101001402060000000005060628096c07020802
2021-07-07 22:59:47,780 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] Raw data: 7eff7d23c0217d227d217d207d347d227d267d207d207d207d207d257d267d26287d296c7d277d227d287d22ea2b7e
2021-07-07 22:59:47,781 DEBUG: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] pppd => sstp (24 bytes)
2021-07-07 22:59:47,781 VERBOSE: [2A636439-AE46-66F0-79A4F1F9/192.168.33.1:61975] ff03c0210201001402060000000005060628096c07020802
...
and from the client end I see:
Jul 7 18:59:47 sstpc[9968]: Resolved 192.168.33.10 to 192.168.33.10
Jul 7 18:59:47 sstpc[9968]: Connected to 192.168.33.10
Jul 7 18:59:47 sstpc[9968]: SSL certificate verification failed: self signed certificate (18)
Jul 7 18:59:47 sstpc[9968]: Server certificated failed verification, ignoring
Jul 7 18:59:47 sstpc[9968]: Sending Connect-Request Message
Jul 7 18:59:47 sstpc[9968]: SEND SSTP CRTL PKT(14)
Jul 7 18:59:47 sstpc[9968]: TYPE(1): CONNECT REQUEST, ATTR(1):
Jul 7 18:59:47 sstpc[9968]: ENCAP PROTO(1): 6
Jul 7 18:59:47 sstpc[9968]: RECV SSTP CRTL PKT(48)
Jul 7 18:59:47 sstpc[9968]: TYPE(2): CONNECT ACK, ATTR(1):
Jul 7 18:59:47 sstpc[9968]: CRYPTO BIND REQ(4): 40
Jul 7 18:59:47 sstpc[9968]: Started PPP Link Negotiation
Jul 7 18:59:47 sstpc[9968]: RECV SSTP DATA PKT(28)
Jul 7 18:59:47 sstpc[9968]: PPP LCP ID: 1 CONFREQ ASYNCMAP: 00 00 00 00 MAGIC: 0xE10C63D5
Jul 7 18:59:47 sstpc[9968]: SEND SSTP DATA PKT(28)
Jul 7 18:59:47 sstpc[9968]: PPP LCP ID: 1 CONFREQ ASYNCMAP: 00 00 00 00 MAGIC: 0xE10C63D5
Jul 7 18:59:47 sstpc[9968]: RECV SSTP DATA PKT(18)
Jul 7 18:59:47 sstpc[9968]: PPP LCP ID: 1 CONFNAK MAGIC: 0xFA49FBD9
Jul 7 18:59:47 sstpc[9968]: SEND SSTP DATA PKT(18)
Jul 7 18:59:47 sstpc[9968]: PPP LCP ID: 1 CONFNAK MAGIC: 0xFA49FBD9
Jul 7 18:59:47 sstpc[9968]: RECV SSTP DATA PKT(28)
Jul 7 18:59:47 sstpc[9968]: PPP LCP ID: 2 CONFREQ ASYNCMAP: 00 00 00 00 MAGIC: 0x5B318996
Jul 7 18:59:47 sstpc[9968]: SEND SSTP DATA PKT(28)
Jul 7 18:59:47 sstpc[9968]: PPP LCP ID: 2 CONFREQ ASYNCMAP: 00 00 00 00 MAGIC: 0x5B318996
Jul 7 18:59:47 sstpc[9968]: RECV SSTP DATA PKT(18)
Jul 7 18:59:47 sstpc[9968]: PPP LCP ID: 2 CONFNAK MAGIC: 0x84DFC505
Jul 7 18:59:47 sstpc[9968]: SEND SSTP DATA PKT(28)
Jul 7 18:59:47 sstpc[9968]: PPP LCP ID: 1 CONFREQ ASYNCMAP: 00 00 00 00 MAGIC: 0x0628096C
Jul 7 18:59:47 sstpc[9968]: RECV SSTP DATA PKT(28)
Jul 7 18:59:47 sstpc[9968]: PPP LCP ID: 1 CONFACK ASYNCMAP: 00 00 00 00 MAGIC: 0x0628096C
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(28)
Jul 7 18:59:50 sstpc[9968]: PPP LCP ID: 1 CONFREQ ASYNCMAP: 00 00 00 00 MAGIC: 0x0628096C
Jul 7 18:59:50 sstpc[9968]: RECV SSTP DATA PKT(28)
Jul 7 18:59:50 sstpc[9968]: PPP LCP ID: 2 CONFREQ ASYNCMAP: 00 00 00 00 MAGIC: 0x5B318996
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(28)
Jul 7 18:59:50 sstpc[9968]: PPP LCP ID: 2 CONFACK ASYNCMAP: 00 00 00 00 MAGIC: 0x5B318996
Jul 7 18:59:50 sstpc[9968]: RECV SSTP DATA PKT(28)
Jul 7 18:59:50 sstpc[9968]: PPP LCP ID: 1 CONFACK ASYNCMAP: 00 00 00 00 MAGIC: 0x0628096C
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(34)
Jul 7 18:59:50 sstpc[9968]: PPP IPCP ID: 1 CONFREQ COMPRESSTYPE: VJ [0x0F 0x01] ADDR: 0.0.0.0 MS_DNS1: 0.0.0.0 MS_DNS2: 0.0.0.0
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(22)
Jul 7 18:59:50 sstpc[9968]: PPP ACSP ID: 1
Jul 7 18:59:50 sstpc[9968]: RECV SSTP DATA PKT(14)
Jul 7 18:59:50 sstpc[9968]: PPP LCP ID: 0 ECHOREQ MAGIC: 0x5B318996
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(16)
Jul 7 18:59:50 sstpc[9968]: PPP LCP ID: 0 ECHOREP MAGIC: 0x0628096C
Jul 7 18:59:50 sstpc[9968]: RECV SSTP DATA PKT(21)
Jul 7 18:59:50 sstpc[9968]: PPP CCP ID: 1 CONFREQ BSD
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(29)
Jul 7 18:59:50 sstpc[9968]: PPP LCP ID: 2 PROTOREJ CCP
Jul 7 18:59:50 sstpc[9968]: RECV SSTP DATA PKT(22)
Jul 7 18:59:50 sstpc[9968]: PPP IPCP ID: 1 CONFREQ COMPRESSTYPE: VJ [0x0F 0x01] ADDR: 192.168.20.1
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(22)
Jul 7 18:59:50 sstpc[9968]: PPP IPCP ID: 1 CONFACK COMPRESSTYPE: VJ [0x0F 0x01] ADDR: 192.168.20.1
Jul 7 18:59:50 sstpc[9968]: RECV SSTP DATA PKT(28)
Jul 7 18:59:50 sstpc[9968]: PPP IPCP ID: 1 CONFNAK ADDR: 192.168.20.2 MS_DNS1: 8.8.8.8 MS_DNS2: 8.8.4.4
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(34)
Jul 7 18:59:50 sstpc[9968]: PPP IPCP ID: 2 CONFREQ COMPRESSTYPE: VJ [0x0F 0x01] ADDR: 192.168.20.2 MS_DNS1: 8.8.8.8 MS_DNS2: 8.8.4.4
Jul 7 18:59:50 sstpc[9968]: RECV SSTP DATA PKT(28)
Jul 7 18:59:50 sstpc[9968]: PPP LCP ID: 3 PROTOREJ ACSP
Jul 7 18:59:50 sstpc[9968]: RECV SSTP DATA PKT(34)
Jul 7 18:59:50 sstpc[9968]: PPP IPCP ID: 2 CONFACK COMPRESSTYPE: VJ [0x0F 0x01] ADDR: 192.168.20.2 MS_DNS1: 8.8.8.8 MS_DNS2: 8.8.4.4
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(88)
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(92)
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(76)
Jul 7 18:59:50 sstpc[9968]: SEND SSTP DATA PKT(92)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(64)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(69)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(69)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(73)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(75)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(83)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(65)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(71)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(99)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(99)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(79)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(79)
Jul 7 18:59:51 sstpc[9968]: SEND SSTP DATA PKT(67)
...
It simply continues sending SSTP DATA PKT non-stop. It looks like the client stopped receiving any data from the server so PPP link negotiation never succeeded (but also never failed for some reason).
p.s.. I also tried to use nodefaultroute on both client and server. However, I don't think PPP connection was established either.
michael-hahn commented
The issue was due to user authentication.