Pluto crashes reproducibly when negotiating tunnel type connection on
the responder side.
I am not a developer, so when requesting further debugging, please send
also brief instructions on how to obtain the necessary information. I
will be happy to help, at least to the extent I am capable of.
In the pluto log, the following appears immediately before pluto crashes:
Aug 20 12:30:05 responder pluto[23155]: | emitting length of IKEv2 Certificate Payload: 2386
Aug 20 12:30:05 responder pluto[23155]: | CHILD SA proposals received
Aug 20 12:30:05 responder pluto[23155]: | going to assemble AUTH payload
Aug 20 12:30:05 responder pluto[23155]: | next payload type: setting 'IKEv2 Certificate Payload'.'next payload type' to IKEv2 Authentication Payload (39:ISAKMP_NEXT_v2AUTH)
Aug 20 12:30:05 responder pluto[23155]: | *****emit IKEv2 Authentication Payload:
Aug 20 12:30:05 responder pluto[23155]: | next payload type: ISAKMP_NEXT_v2SA (0x21)
Aug 20 12:30:05 responder pluto[23155]: | flags: none (0x0)
Aug 20 12:30:05 responder pluto[23155]: | auth method: IKEv2_AUTH_RSA (0x1)
Aug 20 12:30:05 responder pluto[23155]: | next payload type: saving payload location 'IKEv2 Authentication Payload'.'next payload type'
Aug 20 12:30:05 responder pluto[23155]: | started looking for secret for C=CC, O=Mynet, CN=responder.mynet->C=CC, O=Mynet, CN=initiator.mynet of kind PKK_RSA
Aug 20 12:30:05 responder pluto[23155]: | searching for certificate PKK_RSA:AwEAAcC9U vs PKK_RSA:AwEAAcC9U
Aug 20 12:30:07 responder pluto[23155]: | emitting 1024 raw bytes of rsa signature into IKEv2 Authentication Payload
Aug 20 12:30:07 responder pluto[23155]: | rsa signature * * * * * * * * * * * * * * * *
Aug 20 12:30:07 responder pluto[23155]: | rsa signature . . .
...
Aug 20 12:30:07 responder systemd[1]: ipsec.service: Main process exited, code=killed, status=11/SEGV
Aug 20 12:30:07 responder pluto[23155]: | rsa signature * * * * * * * * * * * * * * * *
...
Aug 20 12:30:07 responder pluto[23155]: | rsa signature * * * * * * * * * * * * * * * *
Aug 20 12:30:07 responder pluto[23155]: | emitting length of IKEv2 Authentication Payload: 1032
Aug 20 12:30:07 responder pluto[23155]: | TS: parse initiator traffic selectors
Aug 20 12:30:07 responder pluto[23155]: | ***parse IKEv2 Traffic Selector:
Aug 20 12:30:07 responder pluto[23155]: | TS type: IKEv2_TS_IPV4_ADDR_RANGE (0x7)
Aug 20 12:30:07 responder pluto[23155]: | IP Protocol ID: 0 (0x0)
Aug 20 12:30:07 responder pluto[23155]: | length: 16 (0x10)
Aug 20 12:30:07 responder pluto[23155]: | start port: 0 (0x0)
Aug 20 12:30:07 responder pluto[23155]: | end port: 65535 (0xffff)
Aug 20 12:30:07 responder pluto[23155]: | parsing 4 raw bytes of IKEv2 Traffic Selector into ipv4 ts low
Aug 20 12:30:07 responder pluto[23155]: | ipv4 ts low 0a 00 00 00
Aug 20 12:30:07 responder pluto[23155]: | parsing 4 raw bytes of IKEv2 Traffic Selector into ipv4 ts high
Aug 20 12:30:07 responder pluto[23155]: | ipv4 ts high 0a 00 00 ff
Aug 20 12:30:07 responder pluto[23155]: | TS: parse responder traffic selectors
Aug 20 12:30:07 responder pluto[23155]: | ***parse IKEv2 Traffic Selector:
Aug 20 12:30:07 responder pluto[23155]: | TS type: IKEv2_TS_IPV4_ADDR_RANGE (0x7)
Aug 20 12:30:07 responder pluto[23155]: | IP Protocol ID: 0 (0x0)
Aug 20 12:30:07 responder pluto[23155]: | length: 16 (0x10)
Aug 20 12:30:07 responder pluto[23155]: | start port: 0 (0x0)
Aug 20 12:30:07 responder pluto[23155]: | end port: 65535 (0xffff)
Aug 20 12:30:07 responder pluto[23155]: | parsing 4 raw bytes of IKEv2 Traffic Selector into ipv4 ts low
Aug 20 12:30:07 responder pluto[23155]: | ipv4 ts low b9 63 b1 ad
Aug 20 12:30:07 responder pluto[23155]: | parsing 4 raw bytes of IKEv2 Traffic Selector into ipv4 ts high
Aug 20 12:30:07 responder pluto[23155]: | ipv4 ts high b9 63 b1 ad
Aug 20 12:30:07 responder pluto[23155]: | ikev2_evaluate_connection_fit evaluating our conn="office" I=ini.tia.tor.pub/32:0/0 R=res.pon.der.0/24:0/0 to their:
Aug 20 12:30:07 responder pluto[23155]: | tsi[0]=ini.tia.tor.0-ini.tia.tor.255 proto=0 portrange 0-65535, tsr[0]=res.pon.der.pub-res.pon.der.pub proto=0 portrange 0-65535
Aug 20 12:30:07 responder pluto[23155]: | prefix fitness rejected c office c->name
Aug 20 12:30:07 responder pluto[23155]: | find_host_pair: comparing res.pon.der.priv:500 to 0.0.0.0:500
Aug 20 12:30:07 responder pluto[23155]: | find_host_pair: comparing res.pon.der.priv:500 to ini.tia.tor.pub:500
Aug 20 12:30:07 responder pluto[23155]: | checking hostpair res.pon.der.0/24 -> ini.tia.tor.pub/32 is found
Aug 20 12:30:07 responder pluto[23155]: | match_id a=C=CC, O=Mynet, CN=initiator.mynet
Aug 20 12:30:07 responder pluto[23155]: | b=C=CC, O=Mynet, CN=initiator.mynet
Aug 20 12:30:07 responder pluto[23155]: | results matched
Aug 20 12:30:07 responder pluto[23155]: | investigating connection "office" as a better match
Aug 20 12:30:07 responder pluto[23155]: | ikev2_evaluate_connection_fit evaluating our conn="office" I=ini.tia.tor.pub/32:0/0 R=res.pon.der.0/24:0/0 to their:
Aug 20 12:30:07 responder pluto[23155]: | tsi[0]=ini.tia.tor.0-ini.tia.tor.255 proto=0 portrange 0-65535, tsr[0]=res.pon.der.pub-res.pon.der.pub proto=0 portrange 0-65535
Aug 20 12:30:07 responder pluto[23155]: | prefix fitness rejected d office
Aug 20 12:30:07 responder pluto[23155]: | we did not switch connection
Aug 20 12:30:07 responder pluto[23155]: | failed to find anything; can we instantiate another template?
Aug 20 12:30:08 responder systemd[1]: ipsec.service: Failed with result 'signal'.
Aug 20 12:30:08 responder systemd[1]: ipsec.service: Consumed 12.990s CPU time.
Aug 20 12:30:08 responder systemd[1]: ipsec.service: Scheduled restart job, restart counter is at 2.
Aug 20 12:30:08 responder systemd[1]: Stopped Internet Key Exchange (IKE) Protocol Daemon for IPsec.
Aug 20 12:30:08 responder systemd[1]: ipsec.service: Consumed 12.990s CPU time.
Aug 20 12:30:08 responder systemd[1]: Starting Internet Key Exchange (IKE) Protocol Daemon for IPsec...
Aug 20 12:30:10 responder ipsec[1080]: nflog ipsec capture disabled
Aug 20 12:30:10 responder pluto[1091]: NSS DB directory: sql:/var/lib/ipsec/nss
When watching the wire during connection setup, I can see the usual
beginning of the handshake:
initiator:500 -> responder:500 IKE_SA_INIT Initiator Request
responder:500 -> initiator:500 IKE_SA_INIT Responder Response
initiator:4500 -> responder:4500 IKE_AUTH Initiator Request (multiple fragments)
The last one (after switching to port 4500) is then repeated many times,
since there is no response to it.
The weird thing is that no crash happens when a different initiator host
(on the same local network as the responder, i. e. without the NATs
that occur in the case above) talks to the same responder.
I also have to note that I am not absolutely sure that my config is
correct, but as pluto repeatedly crashes, I am not able to investigate
this any further.
Best regards,
Phil