Hi Paul, ikelifetime is 24h, I change salifetime to the same value. It doesn’t disconnect after an hour, but the issue is there..
As for the remote end it is libreswan 3.27, but this start to happen only after upgrading the server to libreswan 3.41. In the debug when establish for the first time there is the information about the missing certificate: Jan 25 12:03:56 sol pluto[19224]: | authentication succeeded Jan 25 12:03:56 sol pluto[19224]: | thinking about whether to send my certificate: Jan 25 12:03:56 sol pluto[19224]: | I have RSA key: OAKLEY_PRESHARED_KEY cert.type: 0?? Jan 25 12:03:56 sol pluto[19224]: | sendcert: CERT_ALWAYSSEND and I did not get a certificate request Jan 25 12:03:56 sol pluto[19224]: | so do not send cert. Jan 25 12:03:56 sol pluto[19224]: | I did not send a certificate because digital signatures are not being used. (PSK) Jan 25 12:03:56 sol pluto[19224]: | opening output PBS reply packet Jan 25 12:03:56 sol pluto[19224]: | **emit ISAKMP Message: Jan 25 12:03:56 sol pluto[19224]: | initiator SPI: 27 e6 51 cd 5e 56 cb eb Jan 25 12:03:56 sol pluto[19224]: | responder SPI: 5e 32 29 aa 54 2d 89 7e Jan 25 12:03:56 sol pluto[19224]: | next payload type: ISAKMP_NEXT_NONE (0x0) Jan 25 12:03:56 sol pluto[19224]: | ISAKMP version: ISAKMP Version 1.0 (rfc2407) (0x10) Jan 25 12:03:56 sol pluto[19224]: | exchange type: ISAKMP_XCHG_IDPROT (0x2) Jan 25 12:03:56 sol pluto[19224]: | flags: ISAKMP_FLAG_v1_ENCRYPTION (0x1) Jan 25 12:03:56 sol pluto[19224]: | Message ID: 0 (00 00 00 00) Jan 25 12:03:56 sol pluto[19224]: | next payload chain: saving message location 'ISAKMP Message'.'next payload type’ But it does establish the connection. Then after 1h, the log after the authentication is successful and it fail on “CERTIFICATE_UNAVAILABLE”. n 25 12:59:26 sol pluto[19224]: "tunnel8"[6] 95.61.168.133 #24: XAUTH: User [email protected]: Authentication Successful Jan 25 12:59:26 sol pluto[19224]: | opening output PBS xauth_buf Jan 25 12:59:26 sol pluto[19224]: | **emit ISAKMP Message: Jan 25 12:59:26 sol pluto[19224]: | initiator SPI: 66 6a 3c 3e 85 e9 f9 6d Jan 25 12:59:26 sol pluto[19224]: | responder SPI: 7c 4c 08 f8 93 21 f7 2a Jan 25 12:59:26 sol pluto[19224]: | next payload type: ISAKMP_NEXT_NONE (0x0) Jan 25 12:59:26 sol pluto[19224]: | ISAKMP version: ISAKMP Version 1.0 (rfc2407) (0x10) Jan 25 12:59:26 sol pluto[19224]: | exchange type: ISAKMP_XCHG_MODE_CFG (0x6) Jan 25 12:59:26 sol pluto[19224]: | flags: ISAKMP_FLAG_v1_ENCRYPTION (0x1) Jan 25 12:59:26 sol pluto[19224]: | Message ID: 1337103569 (4f b2 94 d1) Jan 25 12:59:26 sol pluto[19224]: | next payload chain: saving message location 'ISAKMP Message'.'next payload type' Jan 25 12:59:26 sol pluto[19224]: | ***emit ISAKMP Hash Payload: Jan 25 12:59:26 sol pluto[19224]: | next payload type: ISAKMP_NEXT_NONE (0x0) Jan 25 12:59:26 sol pluto[19224]: | next payload chain: setting previous 'ISAKMP Message'.'next payload type' to current ISAKMP Hash Payload (8:ISAKMP_NEXT_HASH) Jan 25 12:59:26 sol pluto[19224]: | next payload chain: saving location 'ISAKMP Hash Payload'.'next payload type' in 'xauth_buf' Jan 25 12:59:26 sol pluto[19224]: | emitting 32 zero bytes of HASH DATA into ISAKMP Hash Payload Jan 25 12:59:26 sol pluto[19224]: | emitting length of ISAKMP Hash Payload: 36 Jan 25 12:59:26 sol pluto[19224]: | ***emit ISAKMP Mode Attribute: Jan 25 12:59:26 sol pluto[19224]: | next payload type: ISAKMP_NEXT_NONE (0x0) Jan 25 12:59:26 sol pluto[19224]: | Attr Msg Type: ISAKMP_CFG_SET (0x3) Jan 25 12:59:26 sol pluto[19224]: | Identifier: 0 (00 00) Jan 25 12:59:26 sol pluto[19224]: | next payload chain: setting previous 'ISAKMP Hash Payload'.'next payload type' to current ISAKMP Mode Attribute (14:ISAKMP_NEXT_MODECFG) Jan 25 12:59:26 sol pluto[19224]: | next payload chain: saving location 'ISAKMP Mode Attribute'.'next payload type' in 'xauth_buf' Jan 25 12:59:26 sol pluto[19224]: | ****emit ISAKMP ModeCfg attribute: Jan 25 12:59:26 sol pluto[19224]: | ModeCfg attr type: AF+XAUTH-STATUS (0xc08f) Jan 25 12:59:26 sol pluto[19224]: | length/value: 1 (00 01) Jan 25 12:59:26 sol pluto[19224]: | no IKEv1 message padding required Jan 25 12:59:26 sol pluto[19224]: | emitting length of ISAKMP Mode Attribute: 12 Jan 25 12:59:26 sol pluto[19224]: | XAUTH: status HASH(1): Jan 25 12:59:26 sol pluto[19224]: | 3a 1b b0 42 f5 9e 74 ce ee 4d 35 ac 28 72 99 52 Jan 25 12:59:26 sol pluto[19224]: | a0 e8 1d 79 87 eb e4 be 67 9f 2e f8 15 d6 be 9c Jan 25 12:59:26 sol pluto[19224]: | no IKEv1 message padding required Jan 25 12:59:26 sol pluto[19224]: | emitting length of ISAKMP Message: 76 Jan 25 12:59:26 sol pluto[19224]: | no IKEv1 message padding required Jan 25 12:59:26 sol pluto[19224]: | emitting length of ISAKMP Message: 76 Jan 25 12:59:26 sol pluto[19224]: | state #24 has no .st_event to delete Jan 25 12:59:26 sol pluto[19224]: | #24 STATE_XAUTH_R0: retransmits: cleared Jan 25 12:59:26 sol pluto[19224]: | event_schedule: newref EVENT_RETRANSMIT-pe@0x55a5339d7158 Jan 25 12:59:26 sol pluto[19224]: | inserting event EVENT_RETRANSMIT, timeout in 0.5 seconds for #24 Jan 25 12:59:26 sol pluto[19224]: | libevent_malloc: newref ptr-libevent@0x55a5339c0148 size 128 Jan 25 12:59:26 sol pluto[19224]: | #24 STATE_XAUTH_R0: retransmits: first event in 0.5 seconds; timeout in 60 seconds; limit of 12 retransmits; current time is 333161.099021 Jan 25 12:59:26 sol pluto[19224]: | sending 80 bytes for XAUTH: status through pppeth2.24 from 92.211.123.17:4500 to 95.61.168.133:4500 using UDP (for #24) Jan 25 12:59:26 sol pluto[19224]: | 00 00 00 00 66 6a 3c 3e 85 e9 f9 6d 7c 4c 08 f8 Jan 25 12:59:26 sol pluto[19224]: | 93 21 f7 2a 08 10 06 01 4f b2 94 d1 00 00 00 4c Jan 25 12:59:26 sol pluto[19224]: | e2 5d 4b 96 00 3d 44 96 0a 70 03 93 20 3b 31 93 Jan 25 12:59:26 sol pluto[19224]: | 91 15 5e 42 d7 2d 36 9f b9 d2 ed ed b1 74 97 d4 Jan 25 12:59:26 sol pluto[19224]: | 87 91 46 64 43 9b 76 c6 f4 9c 9d ca 62 1a e7 70 Jan 25 12:59:26 sol pluto[19224]: | parent state #24: XAUTH_R0(established IKE SA) => XAUTH_R1(established IKE SA) Jan 25 12:59:26 sol pluto[19224]: | resume xauth immediate for #24 suppresed complete_v1_state_transition() Jan 25 12:59:26 sol pluto[19224]: | delref mdp@0x55a5339c0448(1->0) (in resume_handler() at server.c:731) Jan 25 12:59:26 sol pluto[19224]: | delref fd@NULL (in free_logger() at log.c:845) Jan 25 12:59:26 sol pluto[19224]: | delref fd@NULL (in free_logger() at log.c:846) Jan 25 12:59:26 sol pluto[19224]: | #24 spent 0.261 (0.261) milliseconds in resume xauth immediate Jan 25 12:59:26 sol pluto[19224]: | stop processing: state #24 connection "tunnel8"[6] 95.61.168.133 from 95.61.168.133:4500 (in resume_handler() at server.c:733) Jan 25 12:59:26 sol pluto[19224]: | libevent_free: delref ptr-libevent@0x55a5339f5538 Jan 25 12:59:26 sol pluto[19224]: | spent 0.00237 (0.00237) milliseconds in udp_read_packet() calling check_incoming_msg_errqueue() Jan 25 12:59:26 sol pluto[19224]: | newref md@0x55a5339c0448(0->1) (in read_message() at demux.c:103) Jan 25 12:59:26 sol pluto[19224]: | *received 76 bytes from 95.61.168.133:4500 on pppeth2.24 92.211.123.17:4500 using UDP Jan 25 12:59:26 sol pluto[19224]: | 43 9f 57 5d 9d 4e b0 ae b2 23 af 61 43 7d 07 5d Jan 25 12:59:26 sol pluto[19224]: | 08 10 05 01 19 09 57 d3 00 00 00 4c 44 ce 04 7d Jan 25 12:59:26 sol pluto[19224]: | 2a 61 eb df 62 1f 8c 41 5a d3 1e 58 d6 6a e3 fa Jan 25 12:59:26 sol pluto[19224]: | f1 7e 8b 9d ae ac b7 69 d4 cb 98 a7 bb 71 ed 4d Jan 25 12:59:26 sol pluto[19224]: | ee 58 47 54 c8 45 42 0f 4e 09 16 c3 Jan 25 12:59:26 sol pluto[19224]: | **parse ISAKMP Message: Jan 25 12:59:26 sol pluto[19224]: | initiator SPI: 43 9f 57 5d 9d 4e b0 ae Jan 25 12:59:26 sol pluto[19224]: | responder SPI: b2 23 af 61 43 7d 07 5d Jan 25 12:59:26 sol pluto[19224]: | next payload type: ISAKMP_NEXT_HASH (0x8) Jan 25 12:59:26 sol pluto[19224]: | ISAKMP version: ISAKMP Version 1.0 (rfc2407) (0x10) Jan 25 12:59:26 sol pluto[19224]: | exchange type: ISAKMP_XCHG_INFO (0x5) Jan 25 12:59:26 sol pluto[19224]: | flags: ISAKMP_FLAG_v1_ENCRYPTION (0x1) Jan 25 12:59:26 sol pluto[19224]: | Message ID: 420042707 (19 09 57 d3) Jan 25 12:59:26 sol pluto[19224]: | length: 76 (00 00 00 4c) Jan 25 12:59:26 sol pluto[19224]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_INFO (5) Jan 25 12:59:26 sol pluto[19224]: | peer and cookies match on #23; msgid=00000000 st_msgid=00000000 st_v1_msgid.phase15=b9ea6076 Jan 25 12:59:26 sol pluto[19224]: | p15 state object #23 found, in STATE_XAUTH_R0 Jan 25 12:59:26 sol pluto[19224]: | State DB: found IKEv1 state #23 in XAUTH_R0 (find_v1_info_state) Jan 25 12:59:26 sol pluto[19224]: | start processing: state #23 connection "tunnel8"[6] 95.61.168.133 from 95.61.168.133:4500 (in process_v1_packet() at ikev1.c:1378) Jan 25 12:59:26 sol pluto[19224]: | #23 is idle Jan 25 12:59:26 sol pluto[19224]: | #23 idle Jan 25 12:59:26 sol pluto[19224]: | received encrypted packet from 95.61.168.133:4500 Jan 25 12:59:26 sol pluto[19224]: | got payload 0x100 (ISAKMP_NEXT_HASH) needed: 0x100 opt: 0x0 Jan 25 12:59:26 sol pluto[19224]: | ***parse ISAKMP Hash Payload: Jan 25 12:59:26 sol pluto[19224]: | next payload type: ISAKMP_NEXT_N (0xb) Jan 25 12:59:26 sol pluto[19224]: | length: 36 (00 24) Jan 25 12:59:26 sol pluto[19224]: | got payload 0x800 (ISAKMP_NEXT_N) needed: 0x0 opt: 0x0 Jan 25 12:59:26 sol pluto[19224]: | ***parse ISAKMP Notification Payload: Jan 25 12:59:26 sol pluto[19224]: | next payload type: ISAKMP_NEXT_NONE (0x0) Jan 25 12:59:26 sol pluto[19224]: | length: 12 (00 0c) Jan 25 12:59:26 sol pluto[19224]: | DOI: ISAKMP_DOI_IPSEC (0x1) Jan 25 12:59:26 sol pluto[19224]: | protocol ID: 1 (01) Jan 25 12:59:26 sol pluto[19224]: | SPI size: 0 (00) Jan 25 12:59:26 sol pluto[19224]: | Notify Message Type: CERTIFICATE_UNAVAILABLE (0x1c) Jan 25 12:59:26 sol pluto[19224]: | informational HASH(1): Jan 25 12:59:26 sol pluto[19224]: | 25 d1 55 70 1c c9 ce 35 cd 7f 09 23 8e 45 4b c4 Jan 25 12:59:26 sol pluto[19224]: | ed 88 2e 3f ee bd 06 1c b0 c0 f0 14 43 41 f8 eb Jan 25 12:59:26 sol pluto[19224]: | received 'informational' message HASH(1) data ok Jan 25 12:59:26 sol pluto[19224]: "tunnel8"[6] 95.61.168.133 #23: ignoring informational payload CERTIFICATE_UNAVAILABLE, msgid=00000000, length=12 I’ve the full log if you need more info. Thanks. -- Saludos / Regards / Cumprimentos António Silva > On 25 Jan 2021, at 16:47, Paul Wouters <[email protected]> wrote: > > On Mon, 25 Jan 2021, Kontakt wrote: > >> what about my case? ;) >> I have no certificate and also disconnects - I have PSK. > > Please set ikelifetime=24h as well ? This is the default value in > libreswan 4.2 (which is pending release) > > Paul > >> pon., 25 sty 2021 o 16:05 Paul Wouters <[email protected]> napisał(a): >> On Mon, 25 Jan 2021, António Silva wrote: >> >> > I’m using PSK. >> >> > Putting extra debug now. >> >> If you are using PSK then the error CERTIFICATE_UNAVAILABLE from the >> remote peer makes no sense whatsoevef. >> >> RFC 2408 states: >> >> 3. Process the Certificate Request. If a requested Certificate >> Type >> with the specified Certificate Authority is not available, then >> the payload is discarded and the following actions are taken: >> >> (a) The event, CERTIFICATE-UNAVAILABLE, MAY be logged in the >> appropriate system audit file. >> >> (b) An Informational Exchange with a Notification payload >> containing the CERTIFICATE-UNAVAILABLE message type MAY be >> sent to the transmitting entity. This action is dictated >> by >> a system security policy. >> >> I guess your debugging will show if libreswan sent any CERT or CERTREQ >> payload that might have confused the other end ? >> >> Paul >> _______________________________________________ >> Swan mailing list >> [email protected] >> https://lists.libreswan.org/mailman/listinfo/swan >>
_______________________________________________ Swan mailing list [email protected] https://lists.libreswan.org/mailman/listinfo/swan
