With kernel-4.14.5-300.fc27, I've reproduced the issue with a locally built xl2tpd-1.3.10.1 that has the following line commented out in the xl2tpd Makefile :

#OSFLAGS+= -DUSE_KERNEL

I've added a comment to the following bug report :
  https://bugzilla.redhat.com/show_bug.cgi?id=1446914

Although I didn't see the 'ppp0: recursion detected' error as in that report, but might not have the debugging turned up to see it.


Others have reported issues with kernel 4.14 also, here is the upstream libreswan bug report :

https://github.com/libreswan/libreswan/issues/140

I tried kernel-4.15.0-0.rc3.git0.1.fc28.x86_64 on Fedora 27 and can confirm I'm able to able to establish a L2TP/IPsec VPN connection.

Unfortunately kernel-4.14.6-300.fc27 in testing still has the issue.

I've changed the bug component from NetworkManager-l2tp to kernel as the bug appears to only exist with kernel 4.14.x

I can confirm that this is very probably a kernel bug, since I cannot establish a host-to-host tunnel with the ipsec-tools (not the NetworkManager).

Can you test 4.14.8? If 4.15-rc3 works that means there is a good chance a fix may have made its way to stable and there were a bunch of networking fixes bewteen 4.14.6 and 4.14.8

After getting the same issue (and spending hours picking through logs and getting nowhere), I found this thread. I have tried this on the --enablerepo=updates-testing, which takes me to kernel 4.14.8. The problem is still occurring. Exactly the same symptoms, with the same 14 second delay.

I have set plutodebug="all" and directed the debug information to a file, which I have copied from the normal stages to where things get weird. Unfortunately, networking is not my forte and I'm not too familiar with the codebase, the terminology, and even what data should/should not be published. As such I've redacted everything that I can't see as being useful through some quick heavy-handed regexps. If there's something that may help, please let me know and I'll add it back in.

I'm not sure how useful this will be, but it might help to get a timeline of events here.


Dec 22 01:55:59: | complete v1 state transition with STF_OK
Dec 22 01:55:59: | doing_xauth:no, t_xauth_client_done:no
Dec 22 01:55:59: | serialno table: hash serialno #1 to head 0x..............
Dec 22 01:55:59: | IKEv1: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
Dec 22 01:55:59: | child state #3: STATE_QUICK_I1(authenticated-ipsec) => STATE_QUICK_I2(authenticated-ipsec)
Dec 22 01:55:59: | ignore states: 0
Dec 22 01:55:59: | half-open-ike states: 0
Dec 22 01:55:59: | open-ike states: 0
Dec 22 01:55:59: | established-anonymous-ike states: 0
Dec 22 01:55:59: | established-authenticated-ike states: 1
Dec 22 01:55:59: | anonymous-ipsec states: 0
Dec 22 01:55:59: | authenticated-ipsec states: 2
Dec 22 01:55:59: | informational states: 0
Dec 22 01:55:59: | unknown states: 0
Dec 22 01:55:59: | category states: 3 count states: 3
Dec 22 01:55:59: | event_already_set, deleting event
Dec 22 01:55:59: | state #3 requesting EVENT_v1_RETRANSMIT to be deleted
Dec 22 01:55:59: | free_event_entry: release EVENT_v1_RETRANSMIT-pe@.........
Dec 22 01:55:59: | sending reply packet to **.***.***.***:4500 (from port 4500)
Dec 22 01:55:59: | sending 56 bytes for STATE_QUICK_I1 through wlp5s0:4500 to **.***.***.***:4500 (using #3)
Dec 22 01:55:59: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:55:59: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:55:59: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:55:59: |   .. .. .. ..  .. .. .. ..
Dec 22 01:55:59: | !event_already_set at reschedule
Dec 22 01:55:59: | event_schedule_ms called for about 27838000 ms
Dec 22 01:55:59: | event_schedule_tv: new EVENT_SA_REPLACE-pe@.........
Dec 22 01:55:59: | event_schedule_tv called for about 27838 seconds and change
Dec 22 01:55:59: | inserting event EVENT_SA_REPLACE, timeout in 27838.000000 seconds for #3
Dec 22 01:55:59: | NAT-T: NAT Traversal detected - their IKE port is '500'
Dec 22 01:55:59: | NAT-T: encaps is 'auto'
Dec 22 01:55:59: "********-****-****-****-************" #3: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP/NAT=>0x******** <0x******** xfrm=3DES_CBC_0-HMAC_SHA1_96 NATOA=none NATD=**.***.***.***:4500 DPD=passive}
Dec 22 01:55:59: | modecfg pull: noquirk policy:push not-client
Dec 22 01:55:59: | phase 1 is done, looking for phase 2 to unpend
Dec 22 01:55:59: | pluto_sd: executing action action: reloading(4), status 0
Dec 22 01:55:59: listening for IKE messages
Dec 22 01:55:59: | Inspecting interface lo 
Dec 22 01:55:59: | found lo with address 127.0.0.1
Dec 22 01:55:59: | Inspecting interface wlp5s0 
Dec 22 01:55:59: | found wlp5s0 with address ***.***.***.***
Dec 22 01:55:59: | found lo with address 0000:0000:0000:0000:0000:0000:0000:0001
Dec 22 01:55:59: | free_event_entry: release EVENT_NULL-pe@0x..............
Dec 22 01:55:59: | refresh. setup callback for interface lo:500 81
Dec 22 01:55:59: | setup callback for interface lo:500 fd 81
Dec 22 01:55:59: | free_event_entry: release EVENT_NULL-pe@0x..............
Dec 22 01:55:59: | refresh. setup callback for interface lo:4500 80
Dec 22 01:55:59: | setup callback for interface lo:4500 fd 80
Dec 22 01:55:59: | free_event_entry: release EVENT_NULL-pe@0x..............
Dec 22 01:55:59: | refresh. setup callback for interface lo:500 79
Dec 22 01:55:59: | setup callback for interface lo:500 fd 79
Dec 22 01:55:59: | free_event_entry: release EVENT_NULL-pe@0x..............
Dec 22 01:55:59: | refresh. setup callback for interface wlp5s0:4500 78
Dec 22 01:55:59: | setup callback for interface wlp5s0:4500 fd 78
Dec 22 01:55:59: | free_event_entry: release EVENT_NULL-pe@0x..............
Dec 22 01:55:59: | refresh. setup callback for interface wlp5s0:500 77
Dec 22 01:55:59: | setup callback for interface wlp5s0:500 fd 77
Dec 22 01:55:59: | certs and keys locked by 'free_preshared_secrets'
Dec 22 01:55:59: forgetting secrets
Dec 22 01:55:59: | certs and keys unlocked by 'free_preshard_secrets'
Dec 22 01:55:59: loading secrets from "/etc/ipsec.secrets"
Dec 22 01:55:59: loading secrets from "/etc/ipsec.d/nm-l2tp-ipsec-********-****-****-****-************.secrets"
Dec 22 01:55:59: | id type added to secret(0x..............) PPK_PSK: %any
Dec 22 01:55:59: | id type added to secret(0x..............) PPK_PSK: ***.***.***.***
Dec 22 01:55:59: | Processing PSK at line 1: passed
Dec 22 01:55:59: | certs and keys locked by 'process_secret'
Dec 22 01:55:59: | certs and keys unlocked by 'process_secret'
Dec 22 01:55:59: | pluto_sd: executing action action: ready(5), status 0
Dec 22 01:55:59: | waitpid returned pid 4246 - status 0 exit status 0
Dec 22 01:55:59: | reaped addconn helper child (status 0)
Dec 22 01:55:59: | waitpid returned no more children


#
# Nothing happens for 10 seconds
#


Dec 22 01:56:09: | received 84 bytes from **.***.***.***:4500 on wlp5s0 (port=4500)
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. .. 
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. .. 
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. .. 
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. .. 
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. .. 
Dec 22 01:56:09: |   .. .. .. ..
Dec 22 01:56:09: | parse ISAKMP Message:
Dec 22 01:56:09: |    initiator cookie:
Dec 22 01:56:09: |   ** ** ** **  ** ** ** **
Dec 22 01:56:09: |    responder cookie:
Dec 22 01:56:09: |   ** ** ** **  ** ** ** **
Dec 22 01:56:09: |    next payload type: ISAKMP_NEXT_HASH (0x8)
Dec 22 01:56:09: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407) (0x10)
Dec 22 01:56:09: |    exchange type: ISAKMP_XCHG_INFO (0x5)
Dec 22 01:56:09: |    flags: ISAKMP_FLAG_v1_ENCRYPTION (0x1)
Dec 22 01:56:09: |    message ID:  ** ** ** **
Dec 22 01:56:09: |    length: 84 (0x54)
Dec 22 01:56:09: |  processing version=1.0 packet with exchange type=ISAKMP_XCHG_INFO (5)
Dec 22 01:56:09: | cookies table: hash icookie ..:..... rcookie ..:..... to ........... head 0x..............
Dec 22 01:56:09: | peer and cookies match on #3; msgid=00000000 st_msgid=1ee7db5b st_msgid_phase15=00000000
Dec 22 01:56:09: | peer and cookies match on #2; msgid=00000000 st_msgid=124acbbb st_msgid_phase15=00000000
Dec 22 01:56:09: | peer and cookies match on #1; msgid=00000000 st_msgid=00000000 st_msgid_phase15=00000000
Dec 22 01:56:09: | p15 state object #1 found, in STATE_MAIN_I4
Dec 22 01:56:09: | processing connection "********-****-****-****-************" #1 **.***.***.***
Dec 22 01:56:09: | last Phase 1 IV:  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | current Phase 1 IV:  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | IV hash sha init
Dec 22 01:56:09: | IV sha hasher: context 0x..............
Dec 22 01:56:09: | IV hash sha digest PH1_IV-bytes@0x.............. (length 8)
Dec 22 01:56:09: | IV hash sha digest MSGID-bytes@0x.............. (length 4)
Dec 22 01:56:09: | IV hash sha final bytes@0x.............. (length 20)
Dec 22 01:56:09: | IV  .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | IV  .. .. .. ..
Dec 22 01:56:09: | computed Phase 2 IV:
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..
Dec 22 01:56:09: | #1 state_busy:2553 st != NULL && st->st_calculating == FALSE;
Dec 22 01:56:09: | received encrypted packet from **.***.***.***:4500
Dec 22 01:56:09: | decrypting 56 bytes using algorithm 3DES_CBC
Dec 22 01:56:09: | NSS ike_alg_nss_cbc: 3des_cbc - enter
Dec 22 01:56:09: | NSS ike_alg_nss_cbc: 3des_cbc - exit
Dec 22 01:56:09: | decrypted:
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | next IV:  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | got payload 0x100  (ISAKMP_NEXT_HASH) needed: 0x100opt: 0x0
Dec 22 01:56:09: | ***parse ISAKMP Hash Payload:
Dec 22 01:56:09: |    next payload type: ISAKMP_NEXT_N (0xb)
Dec 22 01:56:09: |    length: 24 (0x18)
Dec 22 01:56:09: | got payload 0x800  (ISAKMP_NEXT_N) needed: 0x0opt: 0x0
Dec 22 01:56:09: | ***parse ISAKMP Notification Payload:
Dec 22 01:56:09: |    next payload type: ISAKMP_NEXT_NONE (0x0)
Dec 22 01:56:09: |    length: 32 (0x20)
Dec 22 01:56:09: |    DOI: ISAKMP_DOI_IPSEC (0x1)
Dec 22 01:56:09: |    protocol ID: 1 (0x1)
Dec 22 01:56:09: |    SPI size: 16 (0x10)
Dec 22 01:56:09: |    Notify Message Type: R_U_THERE (0x8d28)
Dec 22 01:56:09: | info:  .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | info:  .. .. .. ..
Dec 22 01:56:09: | processing informational R_U_THERE (36136)
Dec 22 01:56:09: | DPD: received R_U_THERE seq:0 monotime:61 (state=#1 name="********-****-****-****-************")
Dec 22 01:56:09: | **emit ISAKMP Message:
Dec 22 01:56:09: |    initiator cookie:
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |    responder cookie:
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |    next payload type: ISAKMP_NEXT_HASH (0x8)
Dec 22 01:56:09: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407) (0x10)
Dec 22 01:56:09: |    exchange type: ISAKMP_XCHG_INFO (0x5)
Dec 22 01:56:09: |    flags: ISAKMP_FLAG_v1_ENCRYPTION (0x1)
Dec 22 01:56:09: |    message ID:  .. .. .. ..
Dec 22 01:56:09: | ***emit ISAKMP Hash Payload:
Dec 22 01:56:09: |    next payload type: ISAKMP_NEXT_N (0xb)
Dec 22 01:56:09: | emitting 20 zero bytes of HASH into ISAKMP Hash Payload
Dec 22 01:56:09: | emitting length of ISAKMP Hash Payload: 24
Dec 22 01:56:09: | ***emit ISAKMP Notification Payload:
Dec 22 01:56:09: |    next payload type: ISAKMP_NEXT_NONE (0x0)
Dec 22 01:56:09: |    DOI: ISAKMP_DOI_IPSEC (0x1)
Dec 22 01:56:09: |    protocol ID: 1 (0x1)
Dec 22 01:56:09: |    SPI size: 16 (0x10)
Dec 22 01:56:09: |    Notify Message Type: R_U_THERE_ACK (0x8d29)
Dec 22 01:56:09: | emitting 8 raw bytes of notify icookie into ISAKMP Notification Payload
Dec 22 01:56:09: | notify icookie  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | emitting 8 raw bytes of notify rcookie into ISAKMP Notification Payload
Dec 22 01:56:09: | notify rcookie  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | emitting 4 raw bytes of notify data into ISAKMP Notification Payload
Dec 22 01:56:09: | notify data  .. .. .. ..
Dec 22 01:56:09: | emitting length of ISAKMP Notification Payload: 32
Dec 22 01:56:09: | hmac PRF sha init symkey-key@0x.............. (size 20)
Dec 22 01:56:09: | extract symkey clone for NSS algorithm: sha, mechanism: SHA_1_HMAC(545), flags: 800
Dec 22 01:56:09: | EXTRACT_KEY_FROM_KEY: key@0x.............., key-offset: 0, key-size: 20, flags: 0x800 -> target: SHA_1_HMAC
Dec 22 01:56:09: | EXTRACT_KEY_FROM_KEY: key-key@0x.............., size: 20 bytes, type/mechanism: EXTRACT_KEY_FROM_KEY (0x..............)
Dec 22 01:56:09: | EXTRACT_KEY_FROM_KEY: new result-key@0x.............., size: 20 bytes, type/mechanism: SHA_1_HMAC (0x..............)
Dec 22 01:56:09: | hmac prf: created sha context 0x.............. from symkey-key@0x..............
Dec 22 01:56:09: | hmac prf: begin sha with context 0x.............. from symkey-key@0x..............
Dec 22 01:56:09: | hmac: release clone-key@0x..............
Dec 22 01:56:09: | hmac PRF sha crypt-prf@0x..............
Dec 22 01:56:09: | hmac PRF sha update data-bytes@0x.............. (length 4)
Dec 22 01:56:09: | hmac PRF sha update data-bytes@0x.............. (length 32)
Dec 22 01:56:09: | hmac PRF sha final-bytes ...
Dec 22 01:56:09: | hmac PRF sha final-bytes@0x.............. (length 20)
Dec 22 01:56:09: | HASH computed:
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..
Dec 22 01:56:09: | last Phase 1 IV:  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | current Phase 1 IV:  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | IV hash sha init
Dec 22 01:56:09: | IV sha hasher: context 0x..............
Dec 22 01:56:09: | IV hash sha digest PH1_IV-bytes@0x.............. (length 8)
Dec 22 01:56:09: | IV hash sha digest MSGID-bytes@0x.............. (length 4)
Dec 22 01:56:09: | IV hash sha final bytes@0x.............. (length 20)
Dec 22 01:56:09: | IV  .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | IV  .. .. .. ..
Dec 22 01:56:09: | computed Phase 2 IV:
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..
Dec 22 01:56:09: | encrypting: ......
Dec 22 01:56:09: | encrypting: ......
Dec 22 01:56:09: | encrypting: ......
Dec 22 01:56:09: | encrypting: ......
Dec 22 01:56:09: | IV:  .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | IV:  .. .. .. ..
Dec 22 01:56:09: | unpadded size is: 56
Dec 22 01:56:09: | encrypting 56 using 3DES_CBC
Dec 22 01:56:09: | NSS ike_alg_nss_cbc: 3des_cbc - enter
Dec 22 01:56:09: | NSS ike_alg_nss_cbc: 3des_cbc - exit
Dec 22 01:56:09: | next IV:  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | no IKEv1 message padding required
Dec 22 01:56:09: | emitting length of ISAKMP Message: 84
Dec 22 01:56:09: | sending 88 bytes for ISAKMP notify through wlp5s0:4500 to **.***.***.***:4500 (using #1)
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..  .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: |   .. .. .. ..  .. .. .. ..
Dec 22 01:56:09: | complete v1 state transition with STF_IGNORE

#
# 4 seconds later, xl2tpd is killed with signal 15 and cleanup begins...
#

Dec 22 01:56:13: | processing connection "********-****-****-****-************"
Dec 22 01:56:13: "********-****-****-****-************": deleting non-instance connection

I think the issue is related to the following commit in kernel-stable 4.14 :

https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git/commit/net/xfrm?h=v4.14.8&id=c9f3f813d462c72dbe412cee6a5cbacf13c4ad5e

which was reverted in kernel 4.15-rc1 :
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/net/xfrm?h=v4.15-rc4&id=94802151894d482e82c324edf2c658f8e6b96508

As mentioned in the comment on the following page for the revert, IPsec is unusable for some people without this revert :

https://patchwork.ozlabs.org/patch/838470/

And looks like the request to queue it up for v4.14-stable didn't make it through.

I haven't been able to test a patched kernel-4.14.8 with that reverted patch as I currently have limited access to resources while on holiday.

*** Bug 1529082 has been marked as a duplicate of this bug. ***

I seemed to have opened a duplicate here:

https://bugzilla.redhat.com/show_bug.cgi?id=1529938

Needless to say I'm having the same issue.

*** Bug 1529938 has been marked as a duplicate of this bug. ***

Tested 4.14.11 today, disappointed to find same problem. This has been a known issue for weeks causing issues for a lot of users, why keep releasing new kernels with the same bug?

Same issue.

Same issue, but it appears to also be happening when I boot into 4.13.9

https://paste.fedoraproject.org/paste/YnQIE00Lc9kXpS4wmuMQHg

The fix for this issue landed in (In reply to Douglas Kosovic from comment #8)
> I think the issue is related to the following commit in kernel-stable 4.14 :
> 
> https://git.kernel.org/pub/scm/linux/kernel/git/stable/linux-stable.git/
> commit/net/xfrm?h=v4.14.8&id=c9f3f813d462c72dbe412cee6a5cbacf13c4ad5e
> 
> which was reverted in kernel 4.15-rc1 :
> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/
> net/xfrm?h=v4.15-rc4&id=94802151894d482e82c324edf2c658f8e6b96508

This landed in v4.14.12, can you test the latest build (https://koji.fedoraproject.org/koji/buildinfo?buildID=1015631 which should make it to updates-testing today) to make sure it's fixed?

Thanks!

Tested w/ the 4.14.13 kernel and I am able to connect to IPsec/L2TP VPNs again.

Fixed.

Host-to-host ipsec with pre-shared keys is also working again with kernel-4.14.13-300.fc27

Great, thanks for testing!