L2TP server, malformed cookie received or the spi expired

RouterOS General
1

I have two routers that had been working with L2TP windows clients before. After upgrading to 6.44.3 clients cannot connect from Windows anymore. I’m getting messages in the log like this:

21:10:41 ipsec,debug 11.22.33.44 malformed cookie received or the spi expired.

where 11.22.33.44 is the IP address of the remote client. On the client side, all I see is “Connecting…” but it never connects.

Was there a known change that may cause this?

FYI the L2TP was setup this way, some months ago:

/ppp profile add name=ipsec_vpn local-address=192.168.13.254 dns-server=192.168.13.254,8.8.8.8
/interface l2tp-server server set enabled=yes default-profile=ipsec_vpn authentication=mschap2 use-ipsec=required
/ip ipsec policy set [ find default=yes ] src-address=0.0.0.0/0 dst-address=0.0.0.0/0 protocol=all proposal=default template=yes
/ip ipsec peer add exchange-mode=main passive=yes name=l2tpserver
/ip ipsec identity add generate-policy=port-override auth-method=pre-shared-key secret="****STRONG_SECRET_HERE****" peer=l2tpserver
/ip ipsec proposal set default  auth-algorithms=sha512,sha256,sha1 enc-algorithms=aes-256-cbc,aes-128-cbc pfs-group=modp2048
/ppp secret add name="my_user_name" password="****" service=l2tp profile=ipsec_vpn remote-address=192.168.13.100
/interface bridge
set arp=proxy-arp 0
; these are moved to the top
/ip firewall filter
add chain=input action=accept protocol=udp port=1701,500,4500
add chain=input action=accept protocol=ipsec-esp
/ip firewall filter
add action=accept chain=input src-address=192.168.13.100 dst-port=53 protocol=udp comment="L2TP dns udp"
add action=accept chain=input src-address=192.168.13.100 dst-port=53 protocol=tcp comment="L2TP dns tcp"

The configuration was not changed on either sides. The only thing changed was that routeros was upgraded.

Under /ip ipsec peer, there is a “This entry in unreachable” message that was not there before:

 /ip ipsec peer> print
Flags: X - disabled, D - dynamic, R - responder
 0  DR name="peer2" passive=yes profile=default exchange-mode=main send-initial-contact=yes

 1   R ;;; This entry is unreachable
       name="l2tpserver" passive=yes profile=default exchange-mode=main send-initial-contact=yes

But I’m not sure if this is a problem (and why it is unreachable?)

2

You have a strange mix of manual and automatic IPsec configuration for L2TP, not sure how it came into existence.

Normally you either set use-ipsec=required and ipsec-secret under /interface l2tp-server server and RouterOS generates the peer and identity for you, or you set use-ipsec=no and have to set up the peer and identity manually.

Here, you have no ipsec-secret, so the dynamically generated identity linked to the dynamically generated peer doesn’t have any either.

The second (manuallly created) peer is unreachable because incoming initiation requests are matched to peers top to bottom until the first one matches; as your two ones have identical local-address, remote-address, and exchange-mode, the first one shadows the second one which is a misconfiguration so common that RouterOS bothers to display the warning.

So either set ipsec-secret under /interface l2tp-server server to the proper value and remove the manually configured peer and indentity, or set use-ipsec to no. The latter would make sense if you were using IPsec for something else than just the L2TP server, but it seems not to be the case.

3

Okay, this is what I did:

/ip ipsec identity
remove 1
/ip ipsec peer
remove 1
/interface l2tp-server server
set ipsec-secret "*********************"

The current config looks like this:

/ip ipsec export
/ip ipsec proposal
set [ find default=yes ] auth-algorithms=sha512,sha256,sha1 enc-algorithms=aes-256-cbc,aes-128-cbc \
    pfs-group=modp2048
/ip ipsec policy
set 0 dst-address=0.0.0.0/0 src-address=0.0.0.0/0
/interface l2tp-server export
/interface l2tp-server server
set authentication=mschap2 default-profile=ipsec_vpn enabled=yes ipsec-secret="*****************" \
    use-ipsec=required

I still can’t connect. I’m going to paste the end of the logs (sorry it is long):

22:41:15 ipsec,debug ===== received 76 bytes from clients.public.ip.1[4500] to 192.168.15.100[4500]
22:41:15 ipsec,debug,packet ae861cf8 44271e69 db8d8af5 8e1bdc50 08100501 6571f704 0000004c ceaf6a5b
22:41:15 ipsec,debug,packet 4b0771c1 f0a9e034 20d81885 2401233f 41e4bb9e 8a72ef61 c611f531 357138d3
22:41:15 ipsec,debug,packet 87be3efb bea37601 a95015e1
22:41:15 ipsec,debug receive Information.
22:41:15 ipsec,debug,packet compute IV for phase2
22:41:15 ipsec,debug,packet phase1 last IV:
22:41:15 ipsec,debug,packet 28c85a80 9b463f57 6571f704
22:41:15 ipsec,debug hash(sha1)
22:41:15 ipsec,debug,packet encryption(3des)
22:41:15 ipsec,debug,packet phase2 IV computed:
22:41:15 ipsec,debug,packet fa29e352 f68f9e68
22:41:15 ipsec,debug,packet encryption(3des)
22:41:15 ipsec,debug,packet IV was saved for next processing:
22:41:15 ipsec,debug,packet bea37601 a95015e1
22:41:15 ipsec,debug,packet encryption(3des)
22:41:15 ipsec,debug,packet with key:
22:41:15 ipsec,debug,packet 1431294b d2894202 cc7ce354 5b926592 b0a86720 640f4522
22:41:15 ipsec,debug,packet decrypted payload by IV:
22:41:15 ipsec,debug,packet fa29e352 f68f9e68
22:41:15 ipsec,debug,packet decrypted payload, but not trimed.
22:41:15 ipsec,debug,packet 0c000018 69cdd981 310435e0 85ee1422 3ea9fd14 3d16b8be 00000010 00000001
22:41:15 ipsec,debug,packet 03040001 54a481fa 00000000 00000000
22:41:15 ipsec,debug,packet padding len=1
22:41:15 ipsec,debug,packet skip to trim padding.
22:41:15 ipsec,debug,packet decrypted.
22:41:15 ipsec,debug,packet ae861cf8 44271e69 db8d8af5 8e1bdc50 08100501 6571f704 0000004c 0c000018
22:41:15 ipsec,debug,packet 69cdd981 310435e0 85ee1422 3ea9fd14 3d16b8be 00000010 00000001 03040001
22:41:15 ipsec,debug,packet 54a481fa 00000000 00000000
22:41:15 ipsec,debug,packet HASH with:
22:41:15 ipsec,debug,packet 6571f704 00000010 00000001 03040001 54a481fa
22:41:15 ipsec,debug,packet hmac(hmac_sha1)
22:41:15 ipsec,debug,packet HASH computed:
22:41:15 ipsec,debug,packet 69cdd981 310435e0 85ee1422 3ea9fd14 3d16b8be
22:41:15 ipsec,debug hash validated.
22:41:15 ipsec,debug begin.
22:41:15 ipsec,debug seen nptype=8(hash) len=24
22:41:15 ipsec,debug seen nptype=12(delete) len=16
22:41:15 ipsec,debug succeed.
22:41:15 ipsec,debug clients.public.ip.1 delete payload for protocol ESP
22:41:15 ipsec purged IPsec-SA proto_id=ESP spi=0x54a481fa
22:41:15 ipsec purged IPsec-SA proto_id=ESP spi=0xd424959
22:41:15 ipsec removing generated policy
22:41:15 ipsec,debug purged SAs.
22:41:15 ipsec,debug ===== received 84 bytes from clients.public.ip.1[4500] to 192.168.15.100[4500]
22:41:15 ipsec,debug,packet ae861cf8 44271e69 db8d8af5 8e1bdc50 08100501 6cf8d595 00000054 f3230e4f
22:41:15 ipsec,debug,packet fdfca03f 1d51048f 2604eb51 a7333c9f f75421d5 ad389912 439bb708 1a907990
22:41:15 ipsec,debug,packet 33fa87f5 1a0e4507 93805d1d 4c91c6fa 2a30e206
22:41:15 ipsec,debug receive Information.
22:41:15 ipsec,debug,packet compute IV for phase2
22:41:15 ipsec,debug,packet phase1 last IV:
22:41:15 ipsec,debug,packet 28c85a80 9b463f57 6cf8d595
22:41:15 ipsec,debug hash(sha1)
22:41:15 ipsec,debug,packet encryption(3des)
22:41:15 ipsec,debug,packet phase2 IV computed:
22:41:15 ipsec,debug,packet ce53c5bb ddb6d061
22:41:15 ipsec,debug,packet encryption(3des)
22:41:15 ipsec,debug,packet IV was saved for next processing:
22:41:15 ipsec,debug,packet 4c91c6fa 2a30e206
22:41:15 ipsec,debug,packet encryption(3des)
22:41:15 ipsec,debug,packet with key:
22:41:15 ipsec,debug,packet 1431294b d2894202 cc7ce354 5b926592 b0a86720 640f4522
22:41:15 ipsec,debug,packet decrypted payload by IV:
22:41:15 ipsec,debug,packet ce53c5bb ddb6d061
22:41:15 ipsec,debug,packet decrypted payload, but not trimed.
22:41:15 ipsec,debug,packet 0c000018 db44e87e c7d24916 f4989586 6b29d036 dc1fb42a 0000001c 00000001
22:41:15 ipsec,debug,packet 01100001 ae861cf8 44271e69 db8d8af5 8e1bdc50 00000000
22:41:15 ipsec,debug,packet padding len=1
22:41:15 ipsec,debug,packet skip to trim padding.
22:41:15 ipsec,debug,packet decrypted.
22:41:15 ipsec,debug,packet ae861cf8 44271e69 db8d8af5 8e1bdc50 08100501 6cf8d595 00000054 0c000018
22:41:15 ipsec,debug,packet db44e87e c7d24916 f4989586 6b29d036 dc1fb42a 0000001c 00000001 01100001
22:41:15 ipsec,debug,packet ae861cf8 44271e69 db8d8af5 8e1bdc50 00000000
22:41:15 ipsec,debug,packet HASH with:
22:41:15 ipsec,debug,packet 6cf8d595 0000001c 00000001 01100001 ae861cf8 44271e69 db8d8af5 8e1bdc50
22:41:15 ipsec,debug,packet hmac(hmac_sha1)
22:41:15 ipsec,debug,packet HASH computed:
22:41:15 ipsec,debug,packet db44e87e c7d24916 f4989586 6b29d036 dc1fb42a
22:41:15 ipsec,debug hash validated.
22:41:15 ipsec,debug begin.
22:41:15 ipsec,debug seen nptype=8(hash) len=24
22:41:15 ipsec,debug seen nptype=12(delete) len=28
22:41:15 ipsec,debug succeed.
22:41:15 ipsec,debug clients.public.ip.1 delete payload for protocol ISAKMP
22:41:15 ipsec,info purging ISAKMP-SA 192.168.15.100[4500]<=>clients.public.ip.1[4500] spi=ae861cf844271e69:db8d8af58e1bdc50.
22:41:15 ipsec purged ISAKMP-SA 192.168.15.100[4500]<=>clients.public.ip.1[4500] spi=ae861cf844271e69:db8d8af58e1bdc50.
22:41:15 ipsec,debug purged SAs.
22:41:15 ipsec,info ISAKMP-SA deleted 192.168.15.100[4500]-clients.public.ip.1[4500] spi:ae861cf844271e69:db8d8af58e1bdc50 rekey:1
22:41:15 ipsec KA remove: 192.168.15.100[4500]->clients.public.ip.1[4500]
22:41:15 ipsec,debug KA tree dump: 192.168.15.100[4500]->clients.public.ip.1[4500] (in_use=1)
22:41:15 ipsec,debug KA removing this one...
-- Ctrl-C to quit. Space prints separator. New entries will appear at bottom.

This IP address 192.168.15.100 appears multiple times in the logs. The actual topology looks like this:

client computer -----> internet -----> ADSL modem/router with NAT ----> [192.168.15.1] ---- DMZ ----> [192.168.15.100] —> l2tp-server —> 192.168.5.0/24 (remote LAN to be connected to)

I’m not sure if having an additional NAT (with DMZ set to the MikroTik router) is a problem or not. Unfortunately, I cannot change that, because the ISP does not want to give me direct access to the public IP, and there is no alternative at this site. And by the way, I was wrong. The modem with the DMZ is also new, it was changed recently, just before the routeros upgrade. So the problem might not be with the OS upgrade.

I don’t see any particular error message in the logs, but it won’t connect. :frowning:

4

On the other router, the suggested changes worked, I can now login. So the remaining problem is with the ISP’s router, it cannot do NAT on IPSEC. I have to call them. Than you for your help!

5

It’s not necessarily a problem of the ISP’s router. The Windows’ embedded VPN client doesn’t handle NAT at server side with default settings, you either have to tweak the registry to change this, or do a trick on the Mikrotik. I’ll link a topic explaining the necessary modifications on Mikrotik side once I get to my PC.

6

Here you go.

7

Very intriguing. :slight_smile: I have to try this (but I can only do it later).

8

Worked like a charm!

And it was so easy to do, I think it is easier than modifying the registry on a single computer!

Just for completeness, if the public ip is 1.2.3.4 and the WAN interface (connected to the outer/NAT router) is your-wan-interface then this will do it:

/interface bridge add name="hidenat"
/ip address add address=1.2.3.4 network=1.2.3.4 netmask=255.255.255.255 interface=hidenat
/ip firewall nat add chain=dstnat place-before=0 action=dst-nat protocol=udp dst-port=500,4500 in-interface=your-wan-interface to-addresses=1.2.3.4