VPN Server on Catalina
I set up a VPN server on my Mac Mini following the instructions on https://robintiwari.com/post/how-to-set-up-vpn-server-on-macos
Assigning IP adresses from 201 to 216.
The ports are open and forwarded to my Mac Mini (and the problem described below also occurs when trying to connect from within the home network).
When connecting with iOS 13 I get the following entries in /var/log/vpnd.log
When trying to connect I get
2019-11-25 20:53:34 CET Incoming call... Address given to client = 192.168.1.205
Mon Nov 25 20:53:34 2019 : Directory Services Authorization plugin initialized
Mon Nov 25 20:53:34 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:34 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:34 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:34 2019 : L2TP incoming call in progress from '192.168.1.1'...
Mon Nov 25 20:53:34 2019 : L2TP received SCCRQ
Mon Nov 25 20:53:34 2019 : L2TP sent SCCRP
2019-11-25 20:53:34 CET Incoming call... Address given to client = 192.168.1.206
Mon Nov 25 20:53:34 2019 : Directory Services Authorization plugin initialized
Mon Nov 25 20:53:34 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:34 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:34 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:34 2019 : L2TP incoming call in progress from '192.168.1.1'...
Mon Nov 25 20:53:34 2019 : L2TP received SCCRQ
Mon Nov 25 20:53:34 2019 : L2TP sent SCCRP
2019-11-25 20:53:36 CET Incoming call... Address given to client = 192.168.1.207
Mon Nov 25 20:53:36 2019 : Directory Services Authorization plugin initialized
Mon Nov 25 20:53:36 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:36 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:36 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:36 2019 : L2TP incoming call in progress from '192.168.1.1'...
Mon Nov 25 20:53:36 2019 : L2TP received SCCRQ
Mon Nov 25 20:53:36 2019 : L2TP sent SCCRP
2019-11-25 20:53:40 CET Incoming call... Address given to client = 192.168.1.208
Mon Nov 25 20:53:40 2019 : Directory Services Authorization plugin initialized
Mon Nov 25 20:53:40 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:40 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:40 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:40 2019 : L2TP incoming call in progress from '192.168.1.1'...
Mon Nov 25 20:53:40 2019 : L2TP received SCCRQ
Mon Nov 25 20:53:40 2019 : L2TP sent SCCRP
2019-11-25 20:53:44 CET Incoming call... Address given to client = 192.168.1.209
Mon Nov 25 20:53:44 2019 : Directory Services Authorization plugin initialized
Mon Nov 25 20:53:44 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:44 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:44 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:44 2019 : L2TP incoming call in progress from '192.168.1.1'...
Mon Nov 25 20:53:44 2019 : L2TP received SCCRQ
Mon Nov 25 20:53:44 2019 : L2TP sent SCCRP
2019-11-25 20:53:48 CET Incoming call... Address given to client = 192.168.1.210
Mon Nov 25 20:53:48 2019 : Directory Services Authorization plugin initialized
Mon Nov 25 20:53:48 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:48 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:48 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:48 2019 : L2TP incoming call in progress from '192.168.1.1'...
Mon Nov 25 20:53:48 2019 : L2TP received SCCRQ
Mon Nov 25 20:53:48 2019 : L2TP sent SCCRP
2019-11-25 20:53:52 CET Incoming call... Address given to client = 192.168.1.211
Mon Nov 25 20:53:52 2019 : Directory Services Authorization plugin initialized
Mon Nov 25 20:53:52 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:52 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:52 2019 : publish_entry SCDSet() failed: Success!
Mon Nov 25 20:53:52 2019 : L2TP incoming call in progress from '192.168.1.1'...
Mon Nov 25 20:53:52 2019 : L2TP received SCCRQ
Mon Nov 25 20:53:52 2019 : L2TP sent SCCRP
2019-11-25 20:53:54 CET --> Client with address = 192.168.1.205 has hungup
2019-11-25 20:53:55 CET --> Client with address = 192.168.1.206 has hungup
2019-11-25 20:53:57 CET --> Client with address = 192.168.1.207 has hungup
2019-11-25 20:54:01 CET --> Client with address = 192.168.1.208 has hungup
2019-11-25 20:54:05 CET --> Client with address = 192.168.1.209 has hungup
2019-11-25 20:54:08 CET --> Client with address = 192.168.1.210 has hungup
2019-11-25 20:54:12 CET --> Client with address = 192.168.1.211 has hungup
Any hints?
Edit
These are the logs on the iPhone trying to connect:
default 21:24:46.761882+0100 pppd NetworkExtension is the controller
default 21:24:46.782624+0100 nesessionmanager Got a new session client connection from pppd(6313)
default 21:24:46.782721+0100 nesessionmanager NESMLegacySession[Casa:5FAFF43E-28EA-45E8-8B44-8D6769CCE159]: Adding a connection for client pppd[6313]
default 21:24:46.783978+0100 pppd publish_entry SCDSet() failed: Success!
default 21:24:46.784915+0100 pppd publish_entry SCDSet() failed: Success!
default 21:24:46.786506+0100 pppd pppd 2.4.2 (Apple version 862) started by root, uid 0
default 21:24:46.789427+0100 pppd l2tp_get_router_address
default 21:24:46.791187+0100 pppd l2tp_get_router_address 192.168.1.1 from dict 1
default 21:24:46.799911+0100 mDNSResponder [R107468] DNSServiceCreateConnection START PID[6313](pppd)
default 21:24:46.799971+0100 mDNSResponder [R107469] DNSServiceQueryRecord(15000, 0, <private>, Addr) START PID[6313](pppd)
default 21:24:46.837876+0100 mDNSResponder [R107469] DNSServiceQueryRecord(15000, 0, <private>, Addr) STOP PID[6313](pppd)
default 21:24:46.841876+0100 pppd L2TP connecting to server 'casa.corti.li' (51.154.164.133)...
default 21:24:46.845226+0100 pppd IPSec connection started
default 21:24:48.066632+0100 pppd IPSec connection established
default 21:24:51.805555+0100 symptomsd TCPPP: 0x16182d840 requesting ModeDefault and already in ModeDefault, no-op
default 21:25:08.066077+0100 pppd L2TP cannot connect to the server
default 21:25:08.072647+0100 mDNSResponder [R107468] DNSServiceCreateConnection STOP PID[6313](pppd)
default 21:25:08.075906+0100 nesessionmanager NESMLegacySession[Casa:5FAFF43E-28EA-45E8-8B44-8D6769CCE159]: Removing a connection for client pppd[6313]
default 21:25:12.317658+0100 callservicesd [FBSSystemAppProxy:0x1051c26b0] Service facility connection invalidated
and (I don't know how to do a filter with an 'or' in the console)
default 21:39:53.074716+0100 racoon plogsetfile: about to add racoon log file: /var/log/racoon.log
default 21:39:53.126744+0100 racoon accepted connection on vpn control socket.
default 21:39:53.126813+0100 racoon received bind command on vpn control socket.
default 21:39:53.134299+0100 racoon New Phase 2
default 21:39:53.134407+0100 racoon state changed to: IKEv1 quick I start
default 21:39:53.135343+0100 racoon IPsec-SA request for 51.154.164.133 queued due to no Phase 1 found.
default 21:39:53.135385+0100 racoon New Phase 1
default 21:39:53.135497+0100 racoon state changed to: IKEv1 ident I start
default 21:39:53.135652+0100 racoon initiate new phase 1 negotiation: 192.168.1.46[500]<=>51.154.164.133[500]
default 21:39:53.135729+0100 racoon begin Identity Protection mode.
default 21:39:53.135798+0100 racoon IPSec Phase 1 started (Initiated by me).
default 21:39:53.137267+0100 racoon Resend Phase 1 packet 6053c723b0e225a8:0000000000000000
default 21:39:53.138278+0100 racoon state changed to: IKEv1 ident I msg1 sent
default 21:39:53.138328+0100 racoon >>>>> phase change status = Phase 1 started by us
default 21:39:53.186357+0100 racoon seen nptype=1(sa)
default 21:39:53.186440+0100 racoon seen nptype=13(vid)
default 21:39:53.186502+0100 racoon seen nptype=13(vid)
default 21:39:53.186568+0100 racoon seen nptype=13(vid)
default 21:39:53.186672+0100 racoon received Vendor ID: RFC 3947
default 21:39:53.186732+0100 racoon received Vendor ID: DPD
default 21:39:53.186796+0100 racoon received broken Microsoft ID: FRAGMENTATION
default 21:39:53.186906+0100 racoon Selected NAT-T version: RFC 3947
default 21:39:53.187036+0100 racoon seen nptype=2(prop)
default 21:39:53.187279+0100 racoon seen nptype=3(trns)
default 21:39:53.189718+0100 racoon state changed to: IKEv1 ident I msg2 rcvd
default 21:39:53.189769+0100 racoon >>>>> phase change status = Phase 1 started by peer
default 21:39:53.288840+0100 racoon Hashing 51.154.164.133[500] with algo #4
default 21:39:53.288944+0100 racoon Hashing 192.168.1.46[500] with algo #4
default 21:39:53.289167+0100 racoon Adding remote and local NAT-D payloads.
default 21:39:53.290071+0100 racoon Resend Phase 1 packet 6053c723b0e225a8:21fbfaa914120f33
default 21:39:53.290121+0100 racoon state changed to: IKEv1 ident I msg3 sent
default 21:39:53.335052+0100 racoon seen nptype=4(ke)
default 21:39:53.335105+0100 racoon seen nptype=10(nonce)
default 21:39:53.335179+0100 racoon seen nptype=20(nat-d)
default 21:39:53.335263+0100 racoon seen nptype=20(nat-d)
default 21:39:53.335395+0100 racoon Hashing 192.168.1.46[500] with algo #4
default 21:39:53.335500+0100 racoon NAT-D payload #0 doesn't match
default 21:39:53.335551+0100 racoon Hashing 51.154.164.133[500] with algo #4
default 21:39:53.335650+0100 racoon NAT-D payload #1 doesn't match
default 21:39:53.335726+0100 racoon NAT detected: ME PEER
default 21:39:53.335791+0100 racoon state changed to: IKEv1 ident I msg4 rcvd
default 21:39:53.388371+0100 racoon added initial-contact payload.
default 21:39:53.389588+0100 racoon Resend Phase 1 packet 6053c723b0e225a8:21fbfaa914120f33
default 21:39:53.389723+0100 racoon state changed to: IKEv1 ident I msg5 sent
default 21:39:53.399147+0100 racoon seen nptype=5(id)
default 21:39:53.399209+0100 racoon seen nptype=8(hash)
default 21:39:53.399528+0100 racoon state changed to: IKEv1 ident I msg6 rcvd
default 21:39:53.399712+0100 racoon state changed to: Phase 1 Established
default 21:39:53.399787+0100 racoon ISAKMP-SA established spi:6053c723b0e225a8:21fbfaa914120f33
default 21:39:53.399966+0100 racoon IPSec Phase 1 established (Initiated by me).
default 21:39:54.229617+0100 racoon initiate new phase 2 negotiation: 192.168.1.46[4500]<=>51.154.164.133[4500]
default 21:39:54.229767+0100 racoon state changed to: IKEv1 quick I start
default 21:39:54.229914+0100 racoon IPSec Phase 2 started (Initiated by me).
default 21:39:54.230504+0100 racoon state changed to: IKEv1 quick I getspi sent
default 21:39:54.231086+0100 racoon >>>>> phase change status = Phase 2 started
default 21:39:54.232083+0100 racoon state changed to: IKEv1 quick I getspi done
default 21:39:54.232311+0100 racoon NAT detected -> UDP encapsulation
default 21:39:54.238396+0100 racoon Resend Phase 2 packet 6053c723b0e225a8:21fbfaa914120f33:000048f6
default 21:39:54.238620+0100 racoon state changed to: IKEv1 quick I msg1 sent
default 21:39:54.268136+0100 racoon seen nptype=8(hash)
default 21:39:54.268294+0100 racoon seen nptype=1(sa)
default 21:39:54.268444+0100 racoon seen nptype=10(nonce)
default 21:39:54.268593+0100 racoon seen nptype=5(id)
default 21:39:54.268739+0100 racoon seen nptype=5(id)
default 21:39:54.268913+0100 racoon seen nptype=21(nat-oa)
default 21:39:54.269064+0100 racoon seen nptype=21(nat-oa)
default 21:39:54.270126+0100 racoon seen nptype=2(prop)
default 21:39:54.270716+0100 racoon seen nptype=3(trns)
default 21:39:54.270864+0100 racoon seen nptype=3(trns)
default 21:39:54.271145+0100 racoon seen nptype=3(trns)
default 21:39:54.271342+0100 racoon seen nptype=3(trns)
default 21:39:54.271507+0100 racoon seen nptype=3(trns)
default 21:39:54.271749+0100 racoon seen nptype=3(trns)
default 21:39:54.278681+0100 racoon seen nptype=2(prop)
default 21:39:54.279242+0100 racoon seen nptype=3(trns)
default 21:39:54.282515+0100 racoon Adjusting my encmode UDP-Transport(4)->Transport(2)
default 21:39:54.282591+0100 racoon Adjusting peer's encmode UDP-Transport(4)->Transport(2)
default 21:39:54.282943+0100 racoon state changed to: IKEv1 quick I msg2 rcvd
default 21:39:54.285733+0100 racoon state changed to: IKEv1 quick I addsa
default 21:39:54.286814+0100 racoon IPsec-SA established (update): satype=3 spi=0x2901e7f mode=1
default 21:39:54.286977+0100 racoon state changed to: Phase 2 established
default 21:39:54.287075+0100 racoon ike_session_ph2_established: ph2 established, spid 22
default 21:39:54.287151+0100 racoon IPSec Phase 2 established (Initiated by me).
default 21:39:54.287306+0100 racoon IPsec-SA established (add): satype=3 spi=0xd19f343 mode=1
default 21:39:54.287547+0100 racoon >>>>> phase change status = Phase 2 established
The VPN server in Catalina does not work.
There are two enabler apps that I know about:
iVPN says that the server in Catalina does not reliably accept connections and the solution is to wait for Apple to fix it (or use Mojave).
VPN Enabler also says that it does not work in Catalina and the author is trying to develop an easy to use OpenVPN server. In the meantime, use Mojave.
A different approach is to use a firewall product like pfSense running on another device or in a virtual machine and enable its VPN server capability. This is not an easy solution!