Skip to content
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

xfrm interface ipsec1 exist after core dump and blocking restart of ipsec service clean #585

Closed
MyOzCam opened this issue Dec 21, 2021 · 4 comments
Labels

Comments

@MyOzCam
Copy link

MyOzCam commented Dec 21, 2021

After setting up plutodebug=base, I got the packet which may cause core dump when ikev1 is not accept

Dec 21 02:43:35 localhost pluto[2787]: | *received 204 bytes from 101.4.62.36:43357 on eth0 192.168.99.102:500 using UDP
Dec 21 02:43:35 localhost pluto[2787]: | 31 27 fc b0 38 10 9e 89 00 00 00 00 00 00 00 00 1'..8...........
Dec 21 02:43:35 localhost pluto[2787]: | 01 10 02 00 00 00 00 00 00 00 00 cc 0d 00 00 5c ...............
Dec 21 02:43:35 localhost pluto[2787]: | 00 00 00 01 00 00 00 01 00 00 00 50 01 01 00 02 ...........P....
Dec 21 02:43:35 localhost pluto[2787]: | 03 00 00 24 01 01 00 00 80 01 00 05 80 02 00 02 ...$............
Dec 21 02:43:35 localhost pluto[2787]: | 80 04 00 02 80 03 00 03 80 0b 00 01 00 0c 00 04 ................
Dec 21 02:43:35 localhost pluto[2787]: | 00 00 0e 10 31 27 fc b0 38 10 9e 89 00 00 00 00 ....1'..8.......
Dec 21 02:43:35 localhost pluto[2787]: | 00 00 00 00 01 10 02 00 00 00 00 00 00 00 00 cc ................
Dec 21 02:43:35 localhost pluto[2787]: | 0d 00 00 5c 00 00 00 01 00 00 00 01 00 00 00 50 ..............P
Dec 21 02:43:35 localhost pluto[2787]: | 01 01 00 02 03 00 00 24 01 01 00 00 80 01 00 05 .......$........
Dec 21 02:43:35 localhost pluto[2787]: | 80 02 00 02 80 04 00 02 80 03 00 03 80 0b 00 01 ................
Dec 21 02:43:35 localhost pluto[2787]: | 00 0c 00 04 00 00 0e 10 00 00 00 24 02 01 00 00 ...........$....
Dec 21 02:43:35 localhost pluto[2787]: | 80 01 00 05 80 02 00 01 80 04 00 02 80 03 00 03 ................
Dec 21 02:43:35 localhost pluto[2787]: | 80 0b 00 01 00 0c 00 04 00 00 0e 10 ............
Dec 21 02:43:35 localhost pluto[2787]: | **parse ISAKMP Message:
Dec 21 02:43:35 localhost pluto[2787]: | initiator SPI: 31 27 fc b0 38 10 9e 89
Dec 21 02:43:35 localhost pluto[2787]: | responder SPI: 00 00 00 00 00 00 00 00
Dec 21 02:43:35 localhost pluto[2787]: | next payload type: ISAKMP_NEXT_SA (0x1)
Dec 21 02:43:35 localhost pluto[2787]: | ISAKMP version: ISAKMP Version 1.0 (rfc2407) (0x10)
Dec 21 02:43:35 localhost pluto[2787]: | exchange type: ISAKMP_XCHG_IDPROT (0x2)
Dec 21 02:43:35 localhost pluto[2787]: | flags: none (0x0)
Dec 21 02:43:35 localhost pluto[2787]: | Message ID: 0 (00 00 00 00)
Dec 21 02:43:35 localhost pluto[2787]: | length: 204 (00 00 00 cc)
Dec 21 02:43:35 localhost pluto[2787]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Dec 21 02:43:35 localhost pluto[2787]: | State DB: IKEv1 state not found (find_state_ikev1_init)
Dec 21 02:43:35 localhost pluto[2787]: | #null state always idle
Dec 21 02:43:35 localhost pluto[2787]: | got payload 0x2 (ISAKMP_NEXT_SA) needed: 0x2 opt: 0x2080
Dec 21 02:43:35 localhost pluto[2787]: | ***parse ISAKMP Security Association Payload:
Dec 21 02:43:35 localhost pluto[2787]: | next payload type: ISAKMP_NEXT_VID (0xd)
Dec 21 02:43:35 localhost pluto[2787]: | length: 92 (00 5c)
Dec 21 02:43:35 localhost pluto[2787]: | DOI: ISAKMP_DOI_IPSEC (0x1)
Dec 21 02:43:35 localhost pluto[2787]: | got payload 0x2000 (ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
Dec 21 02:43:36 localhost systemd[1]: ipsec.service: Main process exited, code=dumped, status=11/SEGV
Dec 21 02:43:36 localhost systemd[1]: ipsec.service: Failed with result 'core-dump'.
Dec 21 02:43:36 localhost systemd[1]: ipsec.service: Consumed 2.706s CPU time.
Dec 21 02:43:36 localhost systemd[1]: ipsec.service: Scheduled restart job, restart counter is at 2.
Dec 21 02:43:36 localhost systemd[1]: Stopped Internet Key Exchange (IKE) Protocol Daemon for IPsec.
Dec 21 02:43:36 localhost systemd[1]: ipsec.service: Consumed 2.706s CPU time.
Dec 21 02:43:36 localhost systemd[1]: Starting Internet Key Exchange (IKE) Protocol Daemon for IPsec...

normally after core dump the IPsec service restart but unfortunately the original xfrm interface was not clear and cause below:

Dec 21 02:43:38 localhost pluto[3815]: "ikev2-cp": conflict ipsec1 already exist cannot support xfrm-interface. May be leftover from previous pluto?
Dec 21 02:43:38 localhost pluto[3815]: "ikev2-cp": failed to add connection: ipsec-interface=1 not supported. device name conflict in xfrm_iface_supported()

This cause the VPN server not accept any connection request and need manual restart the service.

Any workaround?

@paulwouters
Copy link
Member

thanks for capturing the full packet. I replayed it in my test setup but it did not crash. Can you give me your /etc/ipsec.conf and any included conf files so I can fully reproduce your setup?

Dec 21 18:08:21.770741: | *received 204 bytes from 192.1.2.45:48730 on eth1 192.1.2.23:500 using UDP
Dec 21 18:08:21.770778: | 31 27 fc b0 38 10 9e 89 00 00 00 00 00 00 00 00 1'..8...........
Dec 21 18:08:21.770810: | 01 10 02 00 00 00 00 00 00 00 00 cc 0d 00 00 5c ...............
Dec 21 18:08:21.770840: | 00 00 00 01 00 00 00 01 00 00 00 50 01 01 00 02 ...........P....
Dec 21 18:08:21.770870: | 03 00 00 24 01 01 00 00 80 01 00 05 80 02 00 02 ...$............
Dec 21 18:08:21.770900: | 80 04 00 02 80 03 00 03 80 0b 00 01 00 0c 00 04 ................
Dec 21 18:08:21.770944: | 00 00 0e 10 31 27 fc b0 38 10 9e 89 00 00 00 00 ....1'..8.......
Dec 21 18:08:21.770976: | 00 00 00 00 01 10 02 00 00 00 00 00 00 00 00 cc ................
Dec 21 18:08:21.771006: | 0d 00 00 5c 00 00 00 01 00 00 00 01 00 00 00 50 ..............P
Dec 21 18:08:21.771034: | 01 01 00 02 03 00 00 24 01 01 00 00 80 01 00 05 .......$........
Dec 21 18:08:21.771089: | 80 02 00 02 80 04 00 02 80 03 00 03 80 0b 00 01 ................
Dec 21 18:08:21.771118: | 00 0c 00 04 00 00 0e 10 00 00 00 24 02 01 00 00 ...........$....
Dec 21 18:08:21.771147: | 80 01 00 05 80 02 00 01 80 04 00 02 80 03 00 03 ................
Dec 21 18:08:21.771179: | 80 0b 00 01 00 0c 00 04 00 00 0e 10 ............
Dec 21 18:08:21.771210: | **parse ISAKMP Message:
Dec 21 18:08:21.771238: | initiator SPI: 31 27 fc b0 38 10 9e 89
Dec 21 18:08:21.771268: | responder SPI: 00 00 00 00 00 00 00 00
Dec 21 18:08:21.771350: | next payload type: ISAKMP_NEXT_SA (0x1)
Dec 21 18:08:21.771435: | ISAKMP version: ISAKMP Version 1.0 (rfc2407) (0x10)
Dec 21 18:08:21.771459: | exchange type: ISAKMP_XCHG_IDPROT (0x2)
Dec 21 18:08:21.771487: | flags: none (0x0)
Dec 21 18:08:21.771514: | Message ID: 0 (00 00 00 00)
Dec 21 18:08:21.771542: | length: 204 (00 00 00 cc)
Dec 21 18:08:21.771571: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Dec 21 18:08:21.771601: | State DB: IKEv1 state not found (find_state_ikev1_init)
Dec 21 18:08:21.771626: | #null state always idle
Dec 21 18:08:21.771654: | got payload 0x2 (ISAKMP_NEXT_SA) needed: 0x2 opt: 0x2080
Dec 21 18:08:21.771683: | ***parse ISAKMP Security Association Payload:
Dec 21 18:08:21.771720: | next payload type: ISAKMP_NEXT_VID (0xd)
Dec 21 18:08:21.771744: | length: 92 (00 5c)
Dec 21 18:08:21.771772: | DOI: ISAKMP_DOI_IPSEC (0x1)
Dec 21 18:08:21.771799: | got payload 0x2000 (ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
Dec 21 18:08:21.771831: packet from 192.1.2.45:48730: 1-byte length of ISAKMP Vendor ID Payload is smaller than minimum
Dec 21 18:08:21.771861: packet from 192.1.2.45:48730: malformed payload in packet
Dec 21 18:08:21.771892: | delref struct msg_digest@0x55f7409eb7f8(1->0) (process_iface_packet() +305 programs/pluto/demux.c)
Dec 21 18:08:21.771920: | delref logger@0x55f7409d9898(1->0) (process_iface_packet() +305 programs/pluto/demux.c)
Dec 21 18:08:21.771944: | delref fd@NULL (process_iface_packet() +305 programs/pluto/demux.c)
Dec 21 18:08:21.771971: | delref fd@NULL (process_iface_packet() +305 programs/pluto/demux.c)
Dec 21 18:08:21.771998: | delref struct iface_endpoint@0x55f7409eab38(4->3) (process_iface_packet() +305 programs/pluto/demux.c)
Dec 21 18:08:21.772030: | spent 0.402 (1.69) milliseconds in process_iface_packet() reading and processing packet
Dec 21 18:08:22.806161: | processing global timer EVENT_PENDING_DDNS
Dec 21 18:08:22.806475: | FOR_EACH_CONNECTION_.... in (connection_check_ddns() +1184 programs/pluto/initiate.c)
Dec 21 18:08:22.806629: | found "ikev2"
Dec 21 18:08:22.806733: | found "ikev1"
Dec 21 18:08:22.806900: | matches: 2
Dec 21 18:08:22.807010: | FOR_EACH_UNORIENTED_CONNECTION_... in check_orientations
Dec 21 18:08:22.807122: | spent 0.115 (0.642) milliseconds in in connection_check_ddns for hostname lookup
Dec 21 18:08:22.807210: | spent 0.145 (0.738) milliseconds in global timer EVENT_PENDING_DDNS
Dec 21 18:08:22.825421: | processing global timer EVENT_SHUNT_SCAN
Dec 21 18:08:22.825605: | kernel: checking for aged bare shunts from shunt table to expire
Dec 21 18:08:22.825736: | spent 0.0245 (0.126) milliseconds in global timer EVENT_SHUNT_SCAN
Dec 21 18:08:42.834790: | processing global timer EVENT_SHUNT_SCAN
Dec 21 18:08:42.835056: | kernel: checking for aged bare shunts from shunt table to expire
Dec 21 18:08:42.835140: | spent 0.0178 (0.0808) milliseconds in global timer EVENT_SHUNT_SCAN
Dec 21 18:09:02.836858: | processing global timer EVENT_SHUNT_SCAN
Dec 21 18:09:02.837147: | kernel: checking for aged bare shunts from shunt table to expire
Dec 21 18:09:02.837401: | spent 0.0347 (0.249) milliseconds in global timer EVENT_SHUNT_SCAN
Dec 21 18:09:02.837572: | processing global timer EVENT_SD_WATCHDOG
Dec 21 18:09:02.837735: | pluto_sd: executing action action: watchdog(3), status 0
Dec 21 18:09:02.837987: | spent 0.143 (0.251) milliseconds in global timer EVENT_SD_WATCHDOG
Dec 21 18:09:22.825274: | processing global timer EVENT_PENDING_DDNS
Dec 21 18:09:22.825420: | FOR_EACH_CONNECTION_.... in (connection_check_ddns() +1184 programs/pluto/initiate.c)
Dec 21 18:09:22.825599: | found "ikev2"
Dec 21 18:09:22.825665: | found "ikev1"
Dec 21 18:09:22.825732: | matches: 2
Dec 21 18:09:22.825785: | FOR_EACH_UNORIENTED_CONNECTION_... in check_orientations
Dec 21 18:09:22.825906: | spent 0.0695 (0.483) milliseconds in in connection_check_ddns for hostname lookup
Dec 21 18:09:22.825942: | spent 0.0879 (0.524) milliseconds in global timer EVENT_PENDING_DDNS
Dec 21 18:09:22.825980: | processing global timer EVENT_PENDING_PHASE2
Dec 21 18:09:22.826014: | FOR_EACH_CONNECTION_.... in (connection_check_phase2() +1203 programs/pluto/initiate.c)
Dec 21 18:09:22.826048: | found "ikev2"
Dec 21 18:09:22.826081: | pending review: connection "ikev2" was not up, skipped
Dec 21 18:09:22.826114: | found "ikev1"
Dec 21 18:09:22.826145: | pending review: connection "ikev1" was not up, skipped
Dec 21 18:09:22.826172: | matches: 2
Dec 21 18:09:22.826210: | spent 0.0373 (0.197) milliseconds in global timer EVENT_PENDING_PHASE2
Dec 21 18:09:22.826241: | processing global timer EVENT_SHUNT_SCAN
Dec 21 18:09:22.826266: | kernel: checking for aged bare shunts from shunt table to expire
Dec 21 18:09:22.826296: | spent 0.00767 (0.0296) milliseconds in global timer EVENT_SHUNT_SCAN

@paulwouters
Copy link
Member

Never mind. Cagney already fixed it. I can confirm the packet you captured causes a crash in libreswan 4.2 - 4.5

@letoams letoams added the IKEv1 label Dec 22, 2021
@MyOzCam
Copy link
Author

MyOzCam commented Dec 23, 2021

That is correct. Thanks @cagney and the team.

When will release 4.6 which may incorporate this fix?

@letoams
Copy link
Member

letoams commented Dec 23, 2021 via email

@MyOzCam MyOzCam closed this as completed Aug 24, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants