New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

CentOS l2tp doesn't work when update kernel to 4.14 #140

Closed
nothingkill opened this Issue Nov 18, 2017 · 20 comments

Comments

Projects
None yet
10 participants
@nothingkill

nothingkill commented Nov 18, 2017

OS: CentOS release 6.9 (Final)
kernel: 4.14.0-1.el6.elrepo.x86_64
l2tp error log: 'received and ignored empty informational notification payload , retransmitting in response to duplicate packet; already STATE_MAIN_R1'

@bleve

This comment has been minimized.

Show comment
Hide comment
@bleve

bleve Nov 18, 2017

Contributor

That means exactly waht it say: "retransmiting in response to dupliate packet; already STATE_MAIN_R1". Quite possibly firewall blocking packets.

Contributor

bleve commented Nov 18, 2017

That means exactly waht it say: "retransmiting in response to dupliate packet; already STATE_MAIN_R1". Quite possibly firewall blocking packets.

@nothingkill

This comment has been minimized.

Show comment
Hide comment
@nothingkill

nothingkill Nov 18, 2017

@bleve Thanks for your reply. I think that probability is low , libreswan(3.20) works well in kernel version 2.6.32, I just change the grub.conf and select kernel version 4.14.0 and reboot, the vpn client never connect to the server again, the last log from pluto is "received and ignored empty informational notification payload". But if I change the grub.conf back to the kernel 2.6.32 and reboot again, it works!
Then in kernel 4.14.0, I did upgrade libreswan to 3.22, "service ipsec start" didn't work, I checked the ipsec status, it says "pluto is stopped", So I checkout the latest code and build, ipsec final works, but the l2tp still not works, while the vpn client connect to the server, the whole log is

Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: responding to Main Mode from unknown peer 182.xx.xx.xx on port 24603
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: WARNING: connection l2tp-psk PSK length of 9 bytes is too short for sha2_256 PRF in FIPS mode (16 bytes required)
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: STATE_MAIN_R1: sent MR1, expecting MI2
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: STATE_MAIN_R2: sent MR2, expecting MI3
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: ignoring informational payload IPSEC_INITIAL_CONTACT, msgid=00000000, length=28
Nov 19 01:01:55 CentOS pluto[2091]: | ISAKMP Notification Payload
Nov 19 01:01:55 CentOS pluto[2091]: | 00 00 00 1c 00 00 00 01 01 10 60 02
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: Peer ID is ID_IPV4_ADDR: '192.168.2.56'
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: switched from "l2tp-psk"[2] 182.xx.xx.xx to "l2tp-psk"
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: deleting connection "l2tp-psk"[2] 182.xx.xx.xx instance with peer 182.xx.xx.xx {isakmp=#0/ipsec=#0}
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: Peer ID is ID_IPV4_ADDR: '192.168.2.56'
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=PRESHARED_KEY cipher=aes_256 integ=sha2_256 group=MODP2048}
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: the peer proposed: 45.63.xx.xxx/32:17/1701 -> 192.168.2.56/32:17/0
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: NAT-Traversal: received 2 NAT-OA. Using first, ignoring others
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: responding to Quick Mode proposal {msgid:ff555f8f}
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: us: 45.63.xx.xxx[45.32.48.54]:17/1701
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: them: 182.xx.xx.xx[192.168.2.56]:17/63259===192.168.2.56/32
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2 transport mode {ESP/NAT=>0x0d8ea983 <0xbeeaa93a xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=192.168.2.56 NATD=182.xx.xx.xx:24604 DPD=active}
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: STATE_QUICK_R2: IPsec SA established transport mode {ESP/NAT=>0x0d8ea983 <0xbeeaa93a xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=192.168.2.56 NATD=182.xx.xx.xx:24604 DPD=active}
Nov 19 01:01:57 CentOS pluto[2091]: initiate on demand from 45.63.xx.xxx:1701 to 182.xx.xx.xx:63259 proto=17 because: acquire
Nov 19 01:02:17 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: received Delete SA payload: self-deleting ISAKMP State #2
Nov 19 01:02:17 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: deleting state (STATE_MAIN_R3) and sending notification
Nov 19 01:02:17 CentOS pluto[2091]: packet from 182.xx.xx.xx:24604: received and ignored empty informational notification payload
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: DPD: could not find newest phase 1 state - initiating a new one
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: IKEv1 DPD: action - clearing connection kind CK_INSTANCE
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk" #3: deleting state (STATE_QUICK_R2) and sending notification
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk" #3: ESP traffic information: in=0B out=560B
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx: deleting connection "l2tp-psk"[3] 182.xx.xx.xx instance with peer 182.xx.xx.xx {isakmp=#0/ipsec=#0}

If I choose the kernel 2.6.32 and reboot, it works again, the log is

Nov 19 01:06:09 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: responding to Main Mode from unknown peer 182.xx.xx.xx on port 25091
Nov 19 01:06:09 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: WARNING: connection l2tp-psk PSK length of 9 bytes is too short for sha2_256 PRF in FIPS mode (16 bytes required)
Nov 19 01:06:09 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: STATE_MAIN_R1: sent MR1, expecting MI2
Nov 19 01:06:09 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: STATE_MAIN_R2: sent MR2, expecting MI3
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: ignoring informational payload IPSEC_INITIAL_CONTACT, msgid=00000000, length=28
Nov 19 01:06:10 CentOS pluto[1785]: | ISAKMP Notification Payload
Nov 19 01:06:10 CentOS pluto[1785]: | 00 00 00 1c 00 00 00 01 01 10 60 02
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: Peer ID is ID_IPV4_ADDR: '192.168.2.56'
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: switched from "l2tp-psk"[1] 182.xx.xx.xx to "l2tp-psk"
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: deleting connection "l2tp-psk"[1] 182.xx.xx.xx instance with peer 182.xx.xx.xx {isakmp=#0/ipsec=#0}
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: Peer ID is ID_IPV4_ADDR: '192.168.2.56'
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=PRESHARED_KEY cipher=aes_256 integ=sha2_256 group=MODP2048}
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: the peer proposed: 45.63.38.177/32:17/1701 -> 192.168.2.56/32:17/0
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: NAT-Traversal: received 2 NAT-OA. Using first, ignoring others
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: responding to Quick Mode proposal {msgid:046821b0}
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: us: 45.63.38.177[45.32.48.54]:17/1701
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: them: 182.xx.xx.xx[192.168.2.56]:17/56621===192.168.2.56/32
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2 transport mode {ESP/NAT=>0x0300c640 <0x04aca2fb xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=192.168.2.56 NATD=182.xx.xx.xx:25093 DPD=active}
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: STATE_QUICK_R2: IPsec SA established transport mode {ESP/NAT=>0x0300c640 <0x04aca2fb xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=192.168.2.56 NATD=182.xx.xx.xx:25093 DPD=active}

nothingkill commented Nov 18, 2017

@bleve Thanks for your reply. I think that probability is low , libreswan(3.20) works well in kernel version 2.6.32, I just change the grub.conf and select kernel version 4.14.0 and reboot, the vpn client never connect to the server again, the last log from pluto is "received and ignored empty informational notification payload". But if I change the grub.conf back to the kernel 2.6.32 and reboot again, it works!
Then in kernel 4.14.0, I did upgrade libreswan to 3.22, "service ipsec start" didn't work, I checked the ipsec status, it says "pluto is stopped", So I checkout the latest code and build, ipsec final works, but the l2tp still not works, while the vpn client connect to the server, the whole log is

Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: responding to Main Mode from unknown peer 182.xx.xx.xx on port 24603
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: WARNING: connection l2tp-psk PSK length of 9 bytes is too short for sha2_256 PRF in FIPS mode (16 bytes required)
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: STATE_MAIN_R1: sent MR1, expecting MI2
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: STATE_MAIN_R2: sent MR2, expecting MI3
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: ignoring informational payload IPSEC_INITIAL_CONTACT, msgid=00000000, length=28
Nov 19 01:01:55 CentOS pluto[2091]: | ISAKMP Notification Payload
Nov 19 01:01:55 CentOS pluto[2091]: | 00 00 00 1c 00 00 00 01 01 10 60 02
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: Peer ID is ID_IPV4_ADDR: '192.168.2.56'
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[2] 182.xx.xx.xx #2: switched from "l2tp-psk"[2] 182.xx.xx.xx to "l2tp-psk"
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: deleting connection "l2tp-psk"[2] 182.xx.xx.xx instance with peer 182.xx.xx.xx {isakmp=#0/ipsec=#0}
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: Peer ID is ID_IPV4_ADDR: '192.168.2.56'
Nov 19 01:01:55 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=PRESHARED_KEY cipher=aes_256 integ=sha2_256 group=MODP2048}
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: the peer proposed: 45.63.xx.xxx/32:17/1701 -> 192.168.2.56/32:17/0
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: NAT-Traversal: received 2 NAT-OA. Using first, ignoring others
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: responding to Quick Mode proposal {msgid:ff555f8f}
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: us: 45.63.xx.xxx[45.32.48.54]:17/1701
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: them: 182.xx.xx.xx[192.168.2.56]:17/63259===192.168.2.56/32
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2 transport mode {ESP/NAT=>0x0d8ea983 <0xbeeaa93a xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=192.168.2.56 NATD=182.xx.xx.xx:24604 DPD=active}
Nov 19 01:01:57 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: STATE_QUICK_R2: IPsec SA established transport mode {ESP/NAT=>0x0d8ea983 <0xbeeaa93a xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=192.168.2.56 NATD=182.xx.xx.xx:24604 DPD=active}
Nov 19 01:01:57 CentOS pluto[2091]: initiate on demand from 45.63.xx.xxx:1701 to 182.xx.xx.xx:63259 proto=17 because: acquire
Nov 19 01:02:17 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: received Delete SA payload: self-deleting ISAKMP State #2
Nov 19 01:02:17 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #2: deleting state (STATE_MAIN_R3) and sending notification
Nov 19 01:02:17 CentOS pluto[2091]: packet from 182.xx.xx.xx:24604: received and ignored empty informational notification payload
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: DPD: could not find newest phase 1 state - initiating a new one
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx #3: IKEv1 DPD: action - clearing connection kind CK_INSTANCE
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk" #3: deleting state (STATE_QUICK_R2) and sending notification
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk" #3: ESP traffic information: in=0B out=560B
Nov 19 01:02:37 CentOS pluto[2091]: "l2tp-psk"[3] 182.xx.xx.xx: deleting connection "l2tp-psk"[3] 182.xx.xx.xx instance with peer 182.xx.xx.xx {isakmp=#0/ipsec=#0}

If I choose the kernel 2.6.32 and reboot, it works again, the log is

Nov 19 01:06:09 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: responding to Main Mode from unknown peer 182.xx.xx.xx on port 25091
Nov 19 01:06:09 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: WARNING: connection l2tp-psk PSK length of 9 bytes is too short for sha2_256 PRF in FIPS mode (16 bytes required)
Nov 19 01:06:09 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: STATE_MAIN_R1: sent MR1, expecting MI2
Nov 19 01:06:09 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: STATE_MAIN_R2: sent MR2, expecting MI3
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: ignoring informational payload IPSEC_INITIAL_CONTACT, msgid=00000000, length=28
Nov 19 01:06:10 CentOS pluto[1785]: | ISAKMP Notification Payload
Nov 19 01:06:10 CentOS pluto[1785]: | 00 00 00 1c 00 00 00 01 01 10 60 02
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: Peer ID is ID_IPV4_ADDR: '192.168.2.56'
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[1] 182.xx.xx.xx #1: switched from "l2tp-psk"[1] 182.xx.xx.xx to "l2tp-psk"
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: deleting connection "l2tp-psk"[1] 182.xx.xx.xx instance with peer 182.xx.xx.xx {isakmp=#0/ipsec=#0}
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: Peer ID is ID_IPV4_ADDR: '192.168.2.56'
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=PRESHARED_KEY cipher=aes_256 integ=sha2_256 group=MODP2048}
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: the peer proposed: 45.63.38.177/32:17/1701 -> 192.168.2.56/32:17/0
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #1: NAT-Traversal: received 2 NAT-OA. Using first, ignoring others
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: responding to Quick Mode proposal {msgid:046821b0}
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: us: 45.63.38.177[45.32.48.54]:17/1701
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: them: 182.xx.xx.xx[192.168.2.56]:17/56621===192.168.2.56/32
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2 transport mode {ESP/NAT=>0x0300c640 <0x04aca2fb xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=192.168.2.56 NATD=182.xx.xx.xx:25093 DPD=active}
Nov 19 01:06:10 CentOS pluto[1785]: "l2tp-psk"[2] 182.xx.xx.xx #2: STATE_QUICK_R2: IPsec SA established transport mode {ESP/NAT=>0x0300c640 <0x04aca2fb xfrm=AES_CBC_256-HMAC_SHA1_96 NATOA=192.168.2.56 NATD=182.xx.xx.xx:25093 DPD=active}

@bleve

This comment has been minimized.

Show comment
Hide comment
@bleve

bleve Nov 18, 2017

Contributor

Log clearly say "IPsec SA established" that means IPsec part is ok.

Contributor

bleve commented Nov 18, 2017

Log clearly say "IPsec SA established" that means IPsec part is ok.

@letoams

This comment has been minimized.

Show comment
Hide comment
@letoams

letoams Nov 19, 2017

Collaborator
Collaborator

letoams commented Nov 19, 2017

@nothingkill

This comment has been minimized.

Show comment
Hide comment
@nothingkill

nothingkill Nov 19, 2017

@bleve I see.It's not cause by libreswan. I check the client log, the server did not answer l2tp SCCRQ.

nothingkill commented Nov 19, 2017

@bleve I see.It's not cause by libreswan. I check the client log, the server did not answer l2tp SCCRQ.

@nothingkill

This comment has been minimized.

Show comment
Hide comment
@nothingkill

nothingkill Nov 19, 2017

@letoams Still not work, this probably cause by l2tp not libreswan, the vpn client log shows that the server do not send SCCRQ response.Thanks for your advice

nothingkill commented Nov 19, 2017

@letoams Still not work, this probably cause by l2tp not libreswan, the vpn client log shows that the server do not send SCCRQ response.Thanks for your advice

@letoams

This comment has been minimized.

Show comment
Hide comment
@letoams

letoams Nov 29, 2017

Collaborator

the odd line is:
Nov 19 01:01:57 CentOS pluto[2091]: initiate on demand from 45.63.xx.xxx:1701 to 182.xx.xx.xx:63259 proto=17 because: acquire
It should not cause an initiate on demand request from the kernel, since that is a responding connection. Perhaps that kernel is broken?

Collaborator

letoams commented Nov 29, 2017

the odd line is:
Nov 19 01:01:57 CentOS pluto[2091]: initiate on demand from 45.63.xx.xxx:1701 to 182.xx.xx.xx:63259 proto=17 because: acquire
It should not cause an initiate on demand request from the kernel, since that is a responding connection. Perhaps that kernel is broken?

@derkuci

This comment has been minimized.

Show comment
Hide comment
@derkuci

derkuci Dec 6, 2017

Just wanted to add that same issue here. ipsec works fine but the xl2tp part doesn't. The server doesn't seem to receive any requests, while the client log says "

Dec 3 08:20:04 hostname xl2tpd: xl2tpd[2330]: Maximum retries exceeded for tunnel 9820. Closing.

Using kernel 4.13 solves the issue.

derkuci commented Dec 6, 2017

Just wanted to add that same issue here. ipsec works fine but the xl2tp part doesn't. The server doesn't seem to receive any requests, while the client log says "

Dec 3 08:20:04 hostname xl2tpd: xl2tpd[2330]: Maximum retries exceeded for tunnel 9820. Closing.

Using kernel 4.13 solves the issue.

@letoams

This comment has been minimized.

Show comment
Hide comment
@letoams

letoams Dec 6, 2017

Collaborator
Collaborator

letoams commented Dec 6, 2017

@derkuci

This comment has been minimized.

Show comment
Hide comment
@derkuci

derkuci Dec 6, 2017

I put the two lines you suggested in /etc/xl2tpd/xl2tpd.conf (centos 7), but got the following error:

xl2tpd-control: Unable to open /var/run/xl2tpd/l2tp-control for writing: No such file or directory

Sorry this probably doesn't help.

derkuci commented Dec 6, 2017

I put the two lines you suggested in /etc/xl2tpd/xl2tpd.conf (centos 7), but got the following error:

xl2tpd-control: Unable to open /var/run/xl2tpd/l2tp-control for writing: No such file or directory

Sorry this probably doesn't help.

@letoams

This comment has been minimized.

Show comment
Hide comment
@letoams

letoams Dec 6, 2017

Collaborator
Collaborator

letoams commented Dec 6, 2017

@derkuci

This comment has been minimized.

Show comment
Hide comment
@derkuci

derkuci Dec 7, 2017

On CentOS, /var/run is already a symbolic link to /run. So I guess it's not that. Without those two lines, (and with kernel 4.13), xl2tp-control runs fine.

derkuci commented Dec 7, 2017

On CentOS, /var/run is already a symbolic link to /run. So I guess it's not that. Without those two lines, (and with kernel 4.13), xl2tp-control runs fine.

@andreboyko

This comment has been minimized.

Show comment
Hide comment
@andreboyko

andreboyko Dec 8, 2017

Looks like i have the same problem on ArchLinux with kernel 4.14.4-1-ARCH. Downgrading to 4.13.12-1-ARCH solves the problem

Libreswan 3.21 (netkey)
xl2tpd version: xl2tpd-1.3.10

002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: initiating Main Mode
104 "e68a2494-5164-4742-b94d-666f89e20c59" #1: STATE_MAIN_I1: initiate
002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
106 "e68a2494-5164-4742-b94d-666f89e20c59" #1: STATE_MAIN_I2: sent MI2, expecting MR2
002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
108 "e68a2494-5164-4742-b94d-666f89e20c59" #1: STATE_MAIN_I3: sent MI3, expecting MR3
002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: Peer ID is ID_IPV4_ADDR: '10.xxx.xxx.xxx'
002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
004 "e68a2494-5164-4742-b94d-666f89e20c59" #1: STATE_MAIN_I4: ISAKMP SA established {auth=PRESHARED_KEY cipher=3des_cbc_192 integ=sha group=MODP1024}
002 "e68a2494-5164-4742-b94d-666f89e20c59" #2: initiating Quick Mode PSK+ENCRYPT+UP+IKEV1_ALLOW+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO {using isakmp#1 msgid:b0ba3117 proposal=3DES(3)_000-SHA1(2) pfsgroup=no-pfs}
117 "e68a2494-5164-4742-b94d-666f89e20c59" #2: STATE_QUICK_I1: initiate
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: ignoring informational payload IPSEC_RESPONDER_LIFETIME, msgid=b0ba3117, length=28
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: NAT-Traversal: received 2 NAT-OA. Using first, ignoring others
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: our client subnet returned doesn't match my proposal - us:192.xxx.xxx.xxx/32 vs them:194.xx.xxx.xxx/32
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: Allowing questionable proposal anyway [ALLOW_MICROSOFT_BAD_PROPOSAL]
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: peer client subnet returned doesn't match my proposal - us:190.xxx.xxx.xxx/32 vs them:10.xxx.xxx.xxx/32
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: Allowing questionable proposal anyway [ALLOW_MICROSOFT_BAD_PROPOSAL]
002 "e68a2494-5164-4742-b94d-666f89e20c59" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
004 "e68a2494-5164-4742-b94d-666f89e20c59" #2: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP/NAT=>0xbcec3a1e <0x609c3d28 xfrm=3DES_0-HMAC_SHA1 NATOA=189.xxx.xxx.xxx NATD=190.xxx.xxx.xxx:4500 DPD=passive}
nm-l2tp[13414] <info>  Libreswan IPsec tunnel is up.
** Message: xl2tpd started with pid 13852
xl2tpd[13852]: setsockopt recvref[30]: Protocol not available
xl2tpd[13852]: Using l2tp kernel support.
xl2tpd[13852]: xl2tpd version xl2tpd-1.3.10 started on lenovo-pc PID:13852
xl2tpd[13852]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
xl2tpd[13852]: Forked by Scott Balmos and David Stipp, (C) 2001
xl2tpd[13852]: Inherited by Jeff McAdams, (C) 2002
xl2tpd[13852]: Forked again by Xelerance (www.xelerance.com) (C) 2006-2016
xl2tpd[13852]: Listening on IP address 0.0.0.0, port 1701
xl2tpd[13852]: get_call: allocating new tunnel for host 190.xxx.xxx.xxx, port 1701.
xl2tpd[13852]: Connecting to host 190.xxx.xxx.xxx, port 1701
xl2tpd[13852]: control_finish: message type is (null)(0).  Tunnel is 0, call is 0.
xl2tpd[13852]: control_finish: sending SCCRQ
nm-l2tp[13414] <warn>  Looks like pppd didn't initialize our dbus module
nm-l2tp[13414] <info>  Terminated xl2tpd daemon with PID 13852.
xl2tpd[13852]: death_handler: Fatal signal 15 received
xl2tpd[13852]: Connection 0 closed to 190.xxx.xxx.xxx, port 1701 (Server closing)
002 "e68a2494-5164-4742-b94d-666f89e20c59": deleting non-instance connection
** Message: ipsec shut down
nm-l2tp[13414] <warn>  xl2tpd exited with error code 1
** Message: ipsec shut down

andreboyko commented Dec 8, 2017

Looks like i have the same problem on ArchLinux with kernel 4.14.4-1-ARCH. Downgrading to 4.13.12-1-ARCH solves the problem

Libreswan 3.21 (netkey)
xl2tpd version: xl2tpd-1.3.10

002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: initiating Main Mode
104 "e68a2494-5164-4742-b94d-666f89e20c59" #1: STATE_MAIN_I1: initiate
002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
106 "e68a2494-5164-4742-b94d-666f89e20c59" #1: STATE_MAIN_I2: sent MI2, expecting MR2
002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
108 "e68a2494-5164-4742-b94d-666f89e20c59" #1: STATE_MAIN_I3: sent MI3, expecting MR3
002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: Peer ID is ID_IPV4_ADDR: '10.xxx.xxx.xxx'
002 "e68a2494-5164-4742-b94d-666f89e20c59" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
004 "e68a2494-5164-4742-b94d-666f89e20c59" #1: STATE_MAIN_I4: ISAKMP SA established {auth=PRESHARED_KEY cipher=3des_cbc_192 integ=sha group=MODP1024}
002 "e68a2494-5164-4742-b94d-666f89e20c59" #2: initiating Quick Mode PSK+ENCRYPT+UP+IKEV1_ALLOW+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW+ESN_NO {using isakmp#1 msgid:b0ba3117 proposal=3DES(3)_000-SHA1(2) pfsgroup=no-pfs}
117 "e68a2494-5164-4742-b94d-666f89e20c59" #2: STATE_QUICK_I1: initiate
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: ignoring informational payload IPSEC_RESPONDER_LIFETIME, msgid=b0ba3117, length=28
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: NAT-Traversal: received 2 NAT-OA. Using first, ignoring others
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: our client subnet returned doesn't match my proposal - us:192.xxx.xxx.xxx/32 vs them:194.xx.xxx.xxx/32
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: Allowing questionable proposal anyway [ALLOW_MICROSOFT_BAD_PROPOSAL]
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: peer client subnet returned doesn't match my proposal - us:190.xxx.xxx.xxx/32 vs them:10.xxx.xxx.xxx/32
003 "e68a2494-5164-4742-b94d-666f89e20c59" #2: Allowing questionable proposal anyway [ALLOW_MICROSOFT_BAD_PROPOSAL]
002 "e68a2494-5164-4742-b94d-666f89e20c59" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
004 "e68a2494-5164-4742-b94d-666f89e20c59" #2: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP/NAT=>0xbcec3a1e <0x609c3d28 xfrm=3DES_0-HMAC_SHA1 NATOA=189.xxx.xxx.xxx NATD=190.xxx.xxx.xxx:4500 DPD=passive}
nm-l2tp[13414] <info>  Libreswan IPsec tunnel is up.
** Message: xl2tpd started with pid 13852
xl2tpd[13852]: setsockopt recvref[30]: Protocol not available
xl2tpd[13852]: Using l2tp kernel support.
xl2tpd[13852]: xl2tpd version xl2tpd-1.3.10 started on lenovo-pc PID:13852
xl2tpd[13852]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
xl2tpd[13852]: Forked by Scott Balmos and David Stipp, (C) 2001
xl2tpd[13852]: Inherited by Jeff McAdams, (C) 2002
xl2tpd[13852]: Forked again by Xelerance (www.xelerance.com) (C) 2006-2016
xl2tpd[13852]: Listening on IP address 0.0.0.0, port 1701
xl2tpd[13852]: get_call: allocating new tunnel for host 190.xxx.xxx.xxx, port 1701.
xl2tpd[13852]: Connecting to host 190.xxx.xxx.xxx, port 1701
xl2tpd[13852]: control_finish: message type is (null)(0).  Tunnel is 0, call is 0.
xl2tpd[13852]: control_finish: sending SCCRQ
nm-l2tp[13414] <warn>  Looks like pppd didn't initialize our dbus module
nm-l2tp[13414] <info>  Terminated xl2tpd daemon with PID 13852.
xl2tpd[13852]: death_handler: Fatal signal 15 received
xl2tpd[13852]: Connection 0 closed to 190.xxx.xxx.xxx, port 1701 (Server closing)
002 "e68a2494-5164-4742-b94d-666f89e20c59": deleting non-instance connection
** Message: ipsec shut down
nm-l2tp[13414] <warn>  xl2tpd exited with error code 1
** Message: ipsec shut down
@ptbsare

This comment has been minimized.

Show comment
Hide comment
@ptbsare

ptbsare Dec 10, 2017

Same issue here.
Manjaro with kernel 4.14.3-1
Logs are pretty much the same with the above comment.

ptbsare commented Dec 10, 2017

Same issue here.
Manjaro with kernel 4.14.3-1
Logs are pretty much the same with the above comment.

@loqs

This comment has been minimized.

Show comment
Hide comment
@loqs

loqs Dec 12, 2017

@letoams 8f7dc9ae4a7aece9fbc3e6637bdfa38b36bcdf09 was backported in 4.13.16 as 32cfb30c6d6cb3a90846ed9190e6841222afce80 so it depends what version of 4.13 those affected are able to use without issue if that could be the cause.

loqs commented Dec 12, 2017

@letoams 8f7dc9ae4a7aece9fbc3e6637bdfa38b36bcdf09 was backported in 4.13.16 as 32cfb30c6d6cb3a90846ed9190e6841222afce80 so it depends what version of 4.13 those affected are able to use without issue if that could be the cause.

@dkosovic

This comment has been minimized.

Show comment
Hide comment
@dkosovic

dkosovic Dec 15, 2017

Fedora 27 bug report:

On Fedora 27, I can confirm I have the issue with kernel-4.14.5-300.fc27, but not with kernel-4.15.0-0.rc3.git0.1.fc28

dkosovic commented Dec 15, 2017

Fedora 27 bug report:

On Fedora 27, I can confirm I have the issue with kernel-4.14.5-300.fc27, but not with kernel-4.15.0-0.rc3.git0.1.fc28

@libreswan

This comment has been minimized.

Show comment
Hide comment
@libreswan

libreswan Dec 15, 2017

Owner

Thanks for letting us know! I'll add it to the FAQ.

Closing the bug here, since it is clearly a kernel bug, not a libreswan bug

Owner

libreswan commented Dec 15, 2017

Thanks for letting us know! I'll add it to the FAQ.

Closing the bug here, since it is clearly a kernel bug, not a libreswan bug

@dkosovic

This comment has been minimized.

Show comment
Hide comment
@dkosovic

dkosovic Dec 23, 2017

For the benefit of others, this bug is a result of the following commit to linux-stable for kernel 4.14 :

That kernel 4.14 commit breaks IPsec transportation mode when a wildcard address is used on the client side. It was reverted in kernel-4.15-rc1 :

Unfortunately the revert commit reintroduces a stack out-of-bounds bug. We might need to wait for the kernel 4.14 branch to get a fix after kernel 4.15 is released. More details in this netdev linux kernel mailing list thread :

dkosovic commented Dec 23, 2017

For the benefit of others, this bug is a result of the following commit to linux-stable for kernel 4.14 :

That kernel 4.14 commit breaks IPsec transportation mode when a wildcard address is used on the client side. It was reverted in kernel-4.15-rc1 :

Unfortunately the revert commit reintroduces a stack out-of-bounds bug. We might need to wait for the kernel 4.14 branch to get a fix after kernel 4.15 is released. More details in this netdev linux kernel mailing list thread :

@Croissong

This comment has been minimized.

Show comment
Hide comment
@Croissong

Croissong Dec 30, 2017

This appears to be fixed in 4.14.9

Croissong commented Dec 30, 2017

This appears to be fixed in 4.14.9

@dkosovic

This comment has been minimized.

Show comment
Hide comment
@dkosovic

dkosovic Dec 30, 2017

I don't think it is fixed in the kernel 4.14.9 and 4.14.10 source code from kernel.org.

But Arch Linux kernel 4.14.9-1 and 4.14.10-1 have the aforementioned reverted patch from kernel-4.15-rc1 and the stack out-of-bounds patch, i.e. :

as can be confirmed by looking at the commit message for kernel 4.14.9-1 here:

dkosovic commented Dec 30, 2017

I don't think it is fixed in the kernel 4.14.9 and 4.14.10 source code from kernel.org.

But Arch Linux kernel 4.14.9-1 and 4.14.10-1 have the aforementioned reverted patch from kernel-4.15-rc1 and the stack out-of-bounds patch, i.e. :

as can be confirmed by looking at the commit message for kernel 4.14.9-1 here:

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment