could not determine local IP address

libove · July 23, 2020, 2:02pm

I have a RouterBoard 951Ui-2HnD (RouterOS 6.45.9) which has been set up - and had been working - with an SSTP VPN. I don’t think that I changed anything (other than routine RouterOS updates; I’m on the long-term channel). The SSTP VPN stopped working. (Well, the other thing, of course, that “I” “changed” is that the clients are Windows 10, which Microsoft ahem helpfully changes for us every few weeks…)

In the RouterBoard’s logs, I see the old standby “could not determine local IP address”.
But I do have the local IP defined in the /ppp profile:

[admin@MikroTik1] /ppp profile> pri
Flags: * - default 
 0 * name="default" use-mpls=default use-compression=default use-encryption=default only-one=default change-tcp-mss=yes use-upnp=default address-list="" 
     on-up="" on-down="" 

 1 * name="default-encryption" local-address=192.168.255.125 use-mpls=default use-compression=default use-encryption=yes only-one=default change-tcp-mss=yes 
     use-upnp=default address-list="" dns-server=192.168.255.3 on-up="" on-down=""

What I notice in the logs while the client is trying to connect seems to be that the negotiation, after successfully setting up the IPv4 tunnel, goes on to try to set up IPv6 .. which isn’t even enabled on my RouterBoard.

(I disabled IPv6 in the Windows client Network Connection configuration, but the same error results).

So, what am I doing wrong?

many thanks,
-Jay

15:40:59 sstp,ppp,debug : LCP lowerup 
15:40:59 sstp,ppp,debug : LCP open 
15:40:59 sstp,ppp,debug,packet  : sent LCP ConfReq id=0x1 
15:40:59 sstp,ppp,debug,packet    <magic 0x.......> 
15:40:59 sstp,ppp,debug,packet    <auth  mschap2> 
15:40:59 sstp,ppp,debug,packet  : rcvd LCP ConfReq id=0x0 
15:40:59 sstp,ppp,debug,packet    <mru 4091> 
15:40:59 sstp,ppp,debug,packet    <magic 0x........> 
15:40:59 sstp,ppp,debug,packet    <pcomp> 
15:40:59 sstp,ppp,debug,packet    <accomp> 
15:40:59 sstp,ppp,debug,packet    <callback 0x06> 
15:40:59 sstp,ppp,debug,packet  : sent LCP ConfRej id=0x0 
15:40:59 sstp,ppp,debug,packet    <pcomp> 
15:40:59 sstp,ppp,debug,packet    <accomp> 
15:41:00 sstp,ppp,debug,packet  : rcvd LCP ConfAck id=0x1 
15:41:00 sstp,ppp,debug,packet    <magic 0x.......> 
15:41:00 sstp,ppp,debug,packet    <auth  mschap2> 
15:41:00 sstp,ppp,debug,packet  : rcvd LCP ConfReq id=0x1 
15:41:00 sstp,ppp,debug,packet    <mru 4091> 
15:41:00 sstp,ppp,debug,packet    <magic 0x........> 
15:41:00 sstp,ppp,debug,packet    <callback 0x06> 
15:41:00 sstp,ppp,debug,packet  : sent LCP ConfAck id=0x1 
15:41:00 sstp,ppp,debug,packet    <mru 4091> 
15:41:00 sstp,ppp,debug,packet    <magic 0x........> 
15:41:00 sstp,ppp,debug,packet    <callback 0x06> 
15:41:00 sstp,ppp,debug : LCP opened 
15:41:00 sstp,ppp,debug,packet  : sent CHAP Challenge id=0x1 
15:41:00 sstp,ppp,debug,packet     <challenge len=16> 
15:41:00 sstp,ppp,debug,packet     <name MikroTik1> 
15:41:00 sstp,ppp,debug,packet  : rcvd LCP Ident id=0x2 
15:41:00 sstp,ppp,debug,packet     <magic 0x........> 
15:41:00 sstp,ppp,debug,packet     MSRASV5.20 
15:41:00 sstp,ppp,debug,packet  : rcvd LCP Ident id=0x3 
15:41:00 sstp,ppp,debug,packet     <magic 0x........> 
15:41:00 sstp,ppp,debug,packet     MSRAS-0-HOSTNAME 
15:41:00 sstp,ppp,debug,packet  : rcvd LCP Ident id=0x4 
15:41:00 sstp,ppp,debug,packet     <magic 0x........> 
15:41:00 sstp,ppp,debug,packet     ................
15:41:00 sstp,ppp,debug,packet  : rcvd CHAP Response id=0x1 
15:41:00 sstp,ppp,debug,packet     <response len=49> 
15:41:00 sstp,ppp,debug,packet     <name username.local> 
15:41:00 sstp,ppp,info,account username.local logged in, 0.0.0.0 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent CHAP Success id=0x1 
15:41:00 sstp,ppp,debug,packet     S=.................. 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent CBCP CallbackReq id=0x0 
15:41:00 sstp,ppp,debug,packet      01 02 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: rcvd CBCP CallbackResp id=0x0 
15:41:00 sstp,ppp,debug,packet      01 02 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent CBCP CallbackAck id=0x1 
15:41:00 sstp,ppp,debug,packet      01 02 
15:41:00 sstp,ppp,info <sstp-username.local>: authenticated 
15:41:00 sstp,ppp,debug <sstp-username.local>: IPCP lowerup 
15:41:00 sstp,ppp,debug <sstp-username.local>: IPCP open 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent IPCP ConfReq id=0x1 
15:41:00 sstp,ppp,debug,packet     <addr 192.168.255.125> 
15:41:00 sstp,ppp,debug <sstp-username.local>: IPV6CP open 
15:41:00 sstp,ppp,debug <sstp-username.local>: MPLSCP lowerup 
15:41:00 sstp,ppp,debug <sstp-username.local>: MPLSCP open 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent MPLSCP ConfReq id=0x1 
15:41:00 sstp,ppp,debug <sstp-username.local>: BCP open 
15:41:00 sstp,ppp,debug <sstp-username.local>: CCP lowerup 
15:41:00 sstp,ppp,debug <sstp-username.local>: CCP open 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: rcvd IPV6CP ConfReq id=0x5 
15:41:00 sstp,ppp,debug,packet     <interface-identifier 4cba:2cf1:....:....> 
15:41:00 sstp,ppp,debug <sstp-username.local>: received unsupported protocol 0x8057 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent LCP ProtRej id=0x2 
15:41:00 sstp,ppp,debug,packet      ....................
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: rcvd IPCP ConfReq id=0x6 
15:41:00 sstp,ppp,debug,packet     <addr 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet     <ms-dns 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet     <ms-dns 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet     <ms-wins 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet     <ms-wins 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent IPCP ConfRej id=0x6 
15:41:00 sstp,ppp,debug,packet     <addr 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet     <ms-dns 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet     <ms-wins 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet     <ms-wins 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: rcvd LCP ProtRej id=0x7 
15:41:00 sstp,ppp,debug,packet      ...........
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: rcvd IPCP ConfAck id=0x1 
15:41:00 sstp,ppp,debug,packet     <addr 192.168.255.125> 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: rcvd IPCP ConfReq id=0x8 
15:41:00 sstp,ppp,debug,packet     <addr 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent IPCP ConfRej id=0x8 
15:41:00 sstp,ppp,debug,packet     <addr 0.0.0.0> 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: rcvd IPCP TermReq id=0x9 
15:41:00 sstp,ppp,debug,packet     ...............
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent IPCP TermAck id=0x9 
15:41:00 sstp,ppp,debug <sstp-username.local>: LCP close 
15:41:00 sstp,ppp,debug <sstp-username.local>: LCP closed 
15:41:00 sstp,ppp,debug <sstp-username.local>: CCP lowerdown 
15:41:00 sstp,ppp,debug <sstp-username.local>: BCP lowerdown 
15:41:00 sstp,ppp,debug <sstp-username.local>: BCP down event in starting state 
15:41:00 sstp,ppp,debug <sstp-username.local>: IPCP lowerdown 
15:41:00 sstp,ppp,debug <sstp-username.local>: IPV6CP lowerdown 
15:41:00 sstp,ppp,debug <sstp-username.local>: IPV6CP down event in starting state 
15:41:00 sstp,ppp,debug <sstp-username.local>: MPLSCP lowerdown 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent LCP TermReq id=0x3 
15:41:00 sstp,ppp,debug,packet     could not determine local IP address 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: rcvd LCP TermReq id=0xa 
15:41:00 sstp,ppp,debug,packet     ................. 
15:41:00 sstp,ppp,debug,packet  <sstp-username.local>: sent LCP TermAck id=0xa 
15:41:00 sstp,ppp,debug <sstp-username.local>: LCP lowerdown 
15:41:00 sstp,ppp,debug <sstp-username.local>: CCP close 
15:41:00 sstp,ppp,debug <sstp-username.local>: BCP close 
15:41:00 sstp,ppp,debug <sstp-username.local>: IPCP close 
15:41:00 sstp,ppp,debug <sstp-username.local>: IPV6CP close 
15:41:00 sstp,ppp,debug <sstp-username.local>: MPLSCP close 
15:41:00 sstp,ppp,info <sstp-username.local>: terminating... - could not determine local IP address 
15:41:00 sstp,ppp,debug <sstp-username.local>: LCP lowerdown 
15:41:00 sstp,ppp,debug <sstp-username.local>: LCP down event in starting state 
15:41:00 sstp,ppp,info,account username.local logged out, 1 84 56 5 5 
15:41:00 sstp,ppp,info <sstp-username.local>: disconnected

pe1chl · July 23, 2020, 2:15pm

The local address is only defined in the profile default-encryption so you need to make sure that is configured on your SSTP server or your PPP secrets.

libove · July 23, 2020, 2:25pm

I don’t see a place to set the local address in the SSTP server configuration; in the ppp secret it references the default-encryption profile which specifies the local address; shouldn’t that pick it up?
Anyway, I tried it - I explicitly added the local address to this user’s ppp secret, and the problem persists.

Config (updated to include the local-address field):

[admin@MikroTik1] /ppp secret> pri detail
 1   name="username.local" service=any caller-id="" password="password" profile=default-encryption local-address=192.168.255.125 routes="" limit-bytes-in=0 
     limit-bytes-out=0 last-logged-out=jul/23/2020 16:20:59

Log:

16:20:58 sstp,ppp,debug : LCP lowerup 
16:20:58 sstp,ppp,debug : LCP open 
16:20:58 sstp,ppp,debug,packet  : sent LCP ConfReq id=0x1 
16:20:58 sstp,ppp,debug,packet    <magic 0x........> 
16:20:58 sstp,ppp,debug,packet    <auth  mschap2> 
16:20:58 sstp,ppp,debug,packet  : rcvd LCP ConfReq id=0x0 
16:20:58 sstp,ppp,debug,packet    <mru 4091> 
16:20:58 sstp,ppp,debug,packet    <magic 0x........> 
16:20:58 sstp,ppp,debug,packet    <pcomp> 
16:20:58 sstp,ppp,debug,packet    <accomp> 
16:20:58 sstp,ppp,debug,packet    <callback 0x06> 
16:20:58 sstp,ppp,debug,packet  : sent LCP ConfRej id=0x0 
16:20:58 sstp,ppp,debug,packet    <pcomp> 
16:20:58 sstp,ppp,debug,packet    <accomp> 
16:20:58 sstp,ppp,debug,packet  : rcvd LCP ConfAck id=0x1 
16:20:58 sstp,ppp,debug,packet    <magic 0x........> 
16:20:58 sstp,ppp,debug,packet    <auth  mschap2> 
16:20:58 sstp,ppp,debug,packet  : rcvd LCP ConfReq id=0x1 
16:20:58 sstp,ppp,debug,packet    <mru 4091> 
16:20:58 sstp,ppp,debug,packet    <magic 0x........> 
16:20:58 sstp,ppp,debug,packet    <callback 0x06> 
16:20:58 sstp,ppp,debug,packet  : sent LCP ConfAck id=0x1 
16:20:58 sstp,ppp,debug,packet    <mru 4091> 
16:20:58 sstp,ppp,debug,packet    <magic 0x........> 
16:20:58 sstp,ppp,debug,packet    <callback 0x06> 
16:20:58 sstp,ppp,debug : LCP opened 
16:20:58 sstp,ppp,debug,packet  : sent CHAP Challenge id=0x1 
16:20:58 sstp,ppp,debug,packet     <challenge len=16> 
16:20:58 sstp,ppp,debug,packet     <name MikroTik1> 
16:20:58 sstp,ppp,debug,packet  : rcvd LCP Ident id=0x2 
16:20:58 sstp,ppp,debug,packet     <magic 0x........> 
16:20:58 sstp,ppp,debug,packet     MSRASV5.20 
16:20:58 sstp,ppp,debug,packet  : rcvd LCP Ident id=0x3 
16:20:58 sstp,ppp,debug,packet     <magic 0x........> 
16:20:58 sstp,ppp,debug,packet     MSRAS-0-HOSTNAME
16:20:58 sstp,ppp,debug,packet  : rcvd LCP Ident id=0x4 
16:20:58 sstp,ppp,debug,packet     <magic 0x........> 
16:20:58 sstp,ppp,debug,packet     ..............
16:20:58 sstp,ppp,debug,packet  : rcvd CHAP Response id=0x1 
16:20:58 sstp,ppp,debug,packet     <response len=49> 
16:20:58 sstp,ppp,debug,packet     <name username.local> 
16:20:58 sstp,ppp,info,account username.local logged in, 0.0.0.0 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: sent CHAP Success id=0x1 
16:20:58 sstp,ppp,debug,packet     S=...................
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: sent CBCP CallbackReq id=0x0 
16:20:58 sstp,ppp,debug,packet      01 02 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: rcvd CBCP CallbackResp id=0x0 
16:20:58 sstp,ppp,debug,packet      01 02 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: sent CBCP CallbackAck id=0x1 
16:20:58 sstp,ppp,debug,packet      01 02 
16:20:58 sstp,ppp,info <sstp-username.local>: authenticated 
16:20:58 sstp,ppp,debug <sstp-username.local>: IPCP lowerup 
16:20:58 sstp,ppp,debug <sstp-username.local>: IPCP open 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: sent IPCP ConfReq id=0x1 
16:20:58 sstp,ppp,debug,packet     <addr 192.168.255.125> 
16:20:58 sstp,ppp,debug <sstp-username.local>: IPV6CP open 
16:20:58 sstp,ppp,debug <sstp-username.local>: MPLSCP lowerup 
16:20:58 sstp,ppp,debug <sstp-username.local>: MPLSCP open 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: sent MPLSCP ConfReq id=0x1 
16:20:58 sstp,ppp,debug <sstp-username.local>: BCP open 
16:20:58 sstp,ppp,debug <sstp-username.local>: CCP lowerup 
16:20:58 sstp,ppp,debug <sstp-username.local>: CCP open 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: rcvd IPCP ConfReq id=0x5 
16:20:58 sstp,ppp,debug,packet     <addr 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet     <ms-dns 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet     <ms-dns 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet     <ms-wins 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet     <ms-wins 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: sent IPCP ConfRej id=0x5 
16:20:58 sstp,ppp,debug,packet     <addr 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet     <ms-dns 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet     <ms-wins 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet     <ms-wins 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: rcvd LCP ProtRej id=0x6 
16:20:58 sstp,ppp,debug,packet      ..............
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: rcvd IPCP ConfAck id=0x1 
16:20:58 sstp,ppp,debug,packet     <addr 192.168.255.125> 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: rcvd IPCP ConfReq id=0x7 
16:20:58 sstp,ppp,debug,packet     <addr 0.0.0.0> 
16:20:58 sstp,ppp,debug,packet  <sstp-username.local>: sent IPCP ConfRej id=0x7 
16:20:58 sstp,ppp,debug,packet     <addr 0.0.0.0> 
16:20:59 sstp,ppp,debug,packet  <sstp-username.local>: rcvd IPCP TermReq id=0x8 
16:20:59 sstp,ppp,debug,packet      .............
16:20:59 sstp,ppp,debug,packet  <sstp-username.local>: sent IPCP TermAck id=0x8 
16:20:59 sstp,ppp,debug <sstp-username.local>: LCP close 
16:20:59 sstp,ppp,debug <sstp-username.local>: LCP closed 
16:20:59 sstp,ppp,debug <sstp-username.local>: CCP lowerdown 
16:20:59 sstp,ppp,debug <sstp-username.local>: BCP lowerdown 
16:20:59 sstp,ppp,debug <sstp-username.local>: BCP down event in starting state 
16:20:59 sstp,ppp,debug <sstp-username.local>: IPCP lowerdown 
16:20:59 sstp,ppp,debug <sstp-username.local>: IPV6CP lowerdown 
16:20:59 sstp,ppp,debug <sstp-username.local>: IPV6CP down event in starting state 
16:20:59 sstp,ppp,debug <sstp-username.local>: MPLSCP lowerdown 
16:20:59 sstp,ppp,debug,packet  <sstp-username.local>: sent LCP TermReq id=0x2 
16:20:59 sstp,ppp,debug,packet     could not determine local IP address 
16:20:59 sstp,ppp,debug,packet  <sstp-username.local>: rcvd LCP TermReq id=0x9 
16:20:59 sstp,ppp,debug,packet      ...............
16:20:59 sstp,ppp,debug,packet  <sstp-username.local>: sent LCP TermAck id=0x9 
16:20:59 sstp,ppp,debug <sstp-username.local>: LCP lowerdown 
16:20:59 sstp,ppp,debug <sstp-username.local>: CCP close 
16:20:59 sstp,ppp,debug <sstp-username.local>: BCP close 
16:20:59 sstp,ppp,debug <sstp-username.local>: IPCP close 
16:20:59 sstp,ppp,debug <sstp-username.local>: IPV6CP close 
16:20:59 sstp,ppp,debug <sstp-username.local>: MPLSCP close 
16:20:59 sstp,ppp,info <sstp-username.local>: terminating... - could not determine local IP address 
16:20:59 sstp,ppp,debug <sstp-username.local>: LCP lowerdown 
16:20:59 sstp,ppp,debug <sstp-username.local>: LCP down event in starting state 
16:20:59 sstp,ppp,info,account username.local logged out, 0 70 56 4 5 
16:20:59 sstp,ppp,info <sstp-username.local>: disconnected

libove · July 27, 2020, 11:57am

Too weird. I trialled-and-errored it a bit.
It turns out that it was NOT necessary to add the local-address to the ppp secret; having the local-address in the default-encryption profile, and that profile linked to the SSTP-server was fine.
What turns out to have been missing - and I’m damned if I can explain WHY, since this had worked before - was in the ppp profile setting the remote-address to some IP pool.
Looking back at backups, I’ve never had remote-address specified. Is this a change in a recent RouterOS update?
I’ve gone back 18 months in the RouterOS release notes, and not found a mention of remote-address.
So, solved, but, mysterious still. Explanations/ theories will be appreciated.

pe1chl · July 27, 2020, 1:00pm

That is what I said in my first reply. It has to be configured in a profile OR in a secret. The profile has to be linked to the server.
Maybe it worked before without that profile setting, and it chose a local address automatically?
I don’t know, because I never even tried that. I always make an empty bridge (replacement for a “local loopback” as found in other users), assign a subnet to it with an address for the router, and then I use that address as the local address in the default profiles.
I set the remote address in the secret when it has to be fixed, or using a pool when it can be dynamic (a pool is defined with part of the subnet assigned to the empty bridge)
Of course a mechanism to assign the remote address (either fixed or pool) has always been required.