<div dir="ltr"><br>Hello folks,<br><br>First sorry if this email is a bit long, but I tried to analyse my problemas deeper as I can.<br><br>I'm still in the process of validating some new version of openswan/klips to upgrade my current version <a href="http://2.4.9.">2.4.9.</a> The kernel is a 2.6.18 with latest debian patches and without netkey. I don't use certs but only pre-shared keys.<br>
<br>I face a bug where some of my tunnels which used to correctly negociate phase one and two with v2.4.9 can't reach to negociate phase two with newer versions. It seems that klips is not responsible for that as the tunnels works on version :<br>
2.4.9, U2.4.9/K2.4.12, U2.4.10/K2.4.9, U2.4.10/K2.4.12, U2.4.11/K2.4.9, U2.4.11/K2.4.12<br><br>The problem seems to have been introduced into openswan version 2.4.12 as these tested version present the problem :<br>U2.4.12/K2.4.9, 2.4.12, U2.4.13/K2.4.9, U2.4.13/K2.4.12<br>
<br>(I've not tested with klips 2.4.13 as I've fired out this version wich as a fatal bug for us while unloading the ipsec device)<br><br>I'm searching for differencies between tunnels that work and those that doesn't work :<br>
<br>-All working tunnels are with other openswan remote gateways, those which doesn't work are with cisco or racoon.<br>-All working tunnels are configured with esp=3des-sha1, non-working ones uses esp=3des-md5<br>-All working tunnels have only one ipsec SA defined, non-working ones have 2 to 5 ipsec SA<br>
<br>I've modified one working tunnel to set up esp=3des-md5 but it still works.<br>I've added a secondary ipsec SA to a working tunnel but it still works.<br><br><br>All tunnels that have a problem have the same error message : NO_PROPOSAL_CHOSEN (instead of the DPD message)<br>
<br>Here is an example with a tunnel to a racoon server :<br><br>tamerlane:~# ipsec --version<br>Linux Openswan U2.4.11/K2.4.12 (klips)<br>See `ipsec --copyright' for copyright information.<br>Sep 24 08:18:29 tamerlane pluto[2739]: "cortez_primary" #1: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=oakley_3des_cbc_192 prf=oakley_md5 group=modp1024}<br>
Sep 24 08:18:29 tamerlane pluto[2739]: "cortez_primary" #1: Dead Peer Detection (RFC 3706): not enabled because peer did not advertise it<br>Sep 24 08:18:29 tamerlane pluto[2739]: | unpending state #1<br>Sep 24 08:18:29 tamerlane pluto[2739]: | processing connection cortez_primary<br>
Sep 24 08:18:29 tamerlane pluto[2739]: "cortez_primary" #2: initiating Quick Mode PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+UP {using isakmp#1}<br>Sep 24 08:18:29 tamerlane pluto[2739]: | processing connection cortez_primary<br>
Sep 24 08:18:29 tamerlane pluto[2739]: | removing pending policy for "none" {0x80febc8}<br>Sep 24 08:18:29 tamerlane pluto[2739]: | processing connection cortez_primary<br>Sep 24 08:18:29 tamerlane pluto[2739]: "cortez_primary" #2: Dead Peer Detection (RFC 3706): not enabled because peer did not advertise it<br>
Sep 24 08:18:29 tamerlane pluto[2739]: "cortez_primary" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2<br>Sep 24 08:18:29 tamerlane pluto[2739]: "cortez_primary" #2: STATE_QUICK_I2: sent QI2, IPsec SA established {ESP=>0x0d5285bb <0x02ce27da xfrm=3DES_0-HMAC_MD5 NATD=none DPD=none}<br>
<br><br>tamerlane:ipsec.d# ipsec --version<br>Linux Openswan 2.4.12 (klips)<br>See `ipsec --copyright' for copyright information.<br>Sep 24 08:16:08 tamerlane pluto[31064]: "cortez_primary" #1: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=oakley_3des_cbc_192 prf=oakley_md5 group=modp1024}<br>
Sep 24 08:16:08 tamerlane pluto[31064]: "cortez_primary" #1: Dead Peer Detection (RFC 3706): not enabled because peer did not advertise it<br>Sep 24 08:16:08 tamerlane pluto[31064]: | unpending state #1<br>Sep 24 08:16:08 tamerlane pluto[31064]: | processing connection cortez_primary<br>
Sep 24 08:16:08 tamerlane pluto[31064]: "cortez_primary" #2: initiating Quick Mode PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+UP {using isakmp#1}<br>Sep 24 08:16:08 tamerlane pluto[31064]: | processing connection cortez_primary<br>
Sep 24 08:16:08 tamerlane pluto[31064]: | removing pending policy for "none" {0x80fc218}<br>Sep 24 08:16:08 tamerlane pluto[31064]: | processing connection cortez_primary<br>Sep 24 08:16:08 tamerlane pluto[31064]: "cortez_primary" #1: ignoring informational payload, type NO_PROPOSAL_CHOSEN<br>
Sep 24 08:16:08 tamerlane pluto[31064]: "cortez_primary" #1: received and ignored informational message<br><br><br>And another example with Cisco :<br><br>tamerlane:~# ipsec --version<br>Linux Openswan U2.4.11/K2.4.12 (klips)<br>
See `ipsec --copyright' for copyright information.<br>Sep 24 08:34:24 tamerlane pluto[13782]: "sfr_primary" #1: ignoring informational payload, type IPSEC_RESPONDER_LIFETIME<br>Sep 24 08:34:24 tamerlane pluto[13782]: "sfr_primary" #1: received and ignored informational message<br>
Sep 24 08:34:24 tamerlane pluto[13782]: | processing connection sfr_primary<br>Sep 24 08:34:24 tamerlane pluto[13782]: "sfr_primary" #2: Dead Peer Detection (RFC 3706): enabled<br>Sep 24 08:34:24 tamerlane pluto[13782]: | state: 2 requesting event none to be deleted by dpd.c:160<br>
Sep 24 08:34:24 tamerlane pluto[13782]: | state: 1 requesting event EVENT_DPD to be deleted by dpd.c:172<br>Sep 24 08:34:24 tamerlane pluto[13782]: "sfr_primary" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2<br>
Sep 24 08:34:24 tamerlane pluto[13782]: "sfr_primary" #2: STATE_QUICK_I2: sent QI2, IPsec SA established {ESP=>0xd0f8aeb7 <0x00bd73ac xfrm=3DES_0-HMAC_MD5 NATD=none DPD=enabled}<br><br>tamerlane:ipsec.d# ipsec --version<br>
Linux Openswan 2.4.12 (klips)<br>See `ipsec --copyright' for copyright information.<br>Sep 24 08:33:18 tamerlane pluto[9672]: "sfr_primary" #1: ignoring informational payload, type IPSEC_RESPONDER_LIFETIME<br>
Sep 24 08:33:18 tamerlane pluto[9672]: "sfr_primary" #1: received and ignored informational message<br>Sep 24 08:33:18 tamerlane pluto[9672]: | processing connection sfr_primary<br>Sep 24 08:33:18 tamerlane pluto[9672]: "sfr_primary" #1: ignoring informational payload, type NO_PROPOSAL_CHOSEN<br>
Sep 24 08:33:18 tamerlane pluto[9672]: "sfr_primary" #1: received and ignored informational message<br><br><br><br>I tried the full debug mode and noticed some differencies in the logs :<br><br><br>When it works (U2.4.11/K2.4.12):<br>
<br> 1095 : | ******emit ISAKMP IPsec DOI attribute:<br> 1096 : | af+type: AUTH_ALGORITHM<br> 1097 : | length/value: 1<br> 1098 : | [1 is AUTH_ALGORITHM_HMAC_MD5]<br> 1099 : | emitting length of ISAKMP Transform Payload (ESP): 28<br>
1100 : | emitting length of ISAKMP Proposal Payload: 40<br> 1101 : | emitting length of ISAKMP Security Association Payload: 52<br> 1102 : | ***emit ISAKMP Nonce Payload:<br> 1103 : | next payload type: ISAKMP_NEXT_KE<br>
1104 : | emitting 16 raw bytes of Ni into ISAKMP Nonce Payload<br> 1105 : | Ni 5a 2e 92 2a db 97 5e f8 40 0e 7f 6c c6 9f ec 80<br> 1106 : | emitting length of ISAKMP Nonce Payload: 20<br>[...]<br> 1158 : | IV:<br>
1159 : | 6d 8d 61 0a b9 1d 33 71 58 57 c9 a3 9c 79 f1 79<br> 1160 : | encrypting using OAKLEY_3DES_CBC<br> 1161 : | next IV: a3 df ac 13 c6 16 f3 60<br> 1162 : | emitting length of ISAKMP Message: 276<br> 1163 : | sending 276 bytes for quick_outI1 through eth0:1:500 to xxx.xxx.252.134:500:<br>
[...]<br> 1244 : | *received 284 bytes from xxx.xxx.252.134:500 on eth0:1 (port=500)<br>[...]<br> 1263 : | **parse ISAKMP Message:<br> 1264 : | initiator cookie:<br> 1265 : | c4 5e 7d 41 6a 26 f2 ad<br> 1266 : | responder cookie:<br>
1267 : | 18 a2 e8 86 e1 5d a1 0e<br> 1268 : | next payload type: ISAKMP_NEXT_HASH<br> 1269 : | ISAKMP version: ISAKMP Version 1.0<br> 1270 : | exchange type: ISAKMP_XCHG_QUICK<br> 1271 : | flags: ISAKMP_FLAG_ENCRYPTION<br>
1272 : | message ID: e6 e3 2d d9<br> 1273 : | length: 284<br> 1274 : | processing packet with exchange type=ISAKMP_XCHG_QUICK (32)<br> 1275 : | ICOOKIE: c4 5e 7d 41 6a 26 f2 ad<br> 1276 : | RCOOKIE: 18 a2 e8 86 e1 5d a1 0e<br>
1277 : | peer: 5b 44 fc 86<br> 1278 : | state hash entry 19<br> 1279 : | peer and cookies match on #2, provided msgid e6e32dd9 vs e6e32dd9<br> 1280 : | state object #2 found, in STATE_QUICK_I1<br> 1281 : | processing connection sfr_primary<br>
1282 : | received encrypted packet from xxx.xxx.252.134:500<br> 1283 : | decrypting 256 bytes using algorithm OAKLEY_3DES_CBC<br> 1284 : | decrypted:<br>[...]<br> 1301 : | next IV: 42 33 bf ce 6c 17 b2 b9<br> 1302 : | np=8 and sd=0x80e11f0<br>
1303 : | ***parse ISAKMP Hash Payload:<br> 1304 : | next payload type: ISAKMP_NEXT_SA<br> 1305 : | length: 20<br> 1306 : | np=1 and sd=0x80e1160<br> 1307 : | ***parse ISAKMP Security Association Payload:<br>
1308 : | next payload type: ISAKMP_NEXT_NONCE<br> 1309 : | length: 52<br> 1310 : | DOI: ISAKMP_DOI_IPSEC<br> 1311 : | np=10 and sd=0x80e1208<br> 1312 : | ***parse ISAKMP Nonce Payload:<br> 1313 : | next payload type: ISAKMP_NEXT_KE<br>
1314 : | length: 24<br> 1315 : | np=4 and sd=0x80e11b4<br> 1316 : | ***parse ISAKMP Key Exchange Payload:<br> 1317 : | next payload type: ISAKMP_NEXT_ID<br> 1318 : | length: 132<br> 1319 : | np=5 and sd=(nil)<br>
1320 : | ***parse ISAKMP Identification Payload (IPsec DOI):<br> 1321 : | next payload type: ISAKMP_NEXT_ID<br> 1322 : | length: 12<br> 1323 : | ID type: ID_IPV4_ADDR<br> 1324 : | Protocol ID: 0<br>
1325 : | port: 0<br><br><br><br>When it doesn't work (2.4.12):<br><br> 1095 : | ******emit ISAKMP IPsec DOI attribute:<br> 1096 : | af+type: AUTH_ALGORITHM<br> 1097 : | length/value: 1<br> 1098 : | [1 is AUTH_ALGORITHM_HMAC_MD5]<br>
1099 : | emitting length of ISAKMP Transform Payload (ESP): 28<br> 1100 : | emitting length of ISAKMP Proposal Payload: 40<br> 1101 : | out_sa pcn: 0 pn: 1<2 valid_count: 1<br> 1102 : | ****emit ISAKMP Proposal Payload:<br>
1103 : | next payload type: ISAKMP_NEXT_NONE<br> 1104 : | proposal number: 0<br> 1105 : | protocol ID: PROTO_IPCOMP<br> 1106 : | SPI size: 2<br> 1107 : | number of transforms: 1<br> 1108 : | emitting 2 raw bytes of CPI into ISAKMP Proposal Payload<br>
1109 : | CPI b9 f4<br> 1110 : | *****emit ISAKMP Transform Payload (COMP):<br> 1111 : | next payload type: ISAKMP_NEXT_NONE<br> 1112 : | transform number: 0<br> 1113 : | transform ID: IPCOMP_DEFLAT<br>
1114 : | ******emit ISAKMP IPsec DOI attribute:<br> 1115 : | af+type: ENCAPSULATION_MODE<br> 1116 : | length/value: 1<br> 1117 : | [1 is ENCAPSULATION_MODE_TUNNEL]<br> 1118 : | ******emit ISAKMP IPsec DOI attribute:<br>
1119 : | af+type: SA_LIFE_TYPE<br> 1120 : | length/value: 1<br> 1121 : | [1 is SA_LIFE_TYPE_SECONDS]<br> 1122 : | ******emit ISAKMP IPsec DOI attribute:<br> 1123 : | af+type: SA_LIFE_DURATION<br> 1124 : | length/value: 3600<br>
1125 : | emitting length of ISAKMP Transform Payload (COMP): 20<br> 1126 : | emitting length of ISAKMP Proposal Payload: 30<br> 1127 : | emitting length of ISAKMP Security Association Payload: 82<br> 1128 : | ***emit ISAKMP Nonce Payload:<br>
1129 : | next payload type: ISAKMP_NEXT_KE<br> 1130 : | emitting 16 raw bytes of Ni into ISAKMP Nonce Payload<br> 1131 : | Ni 19 07 c2 30 63 91 f3 cd 69 30 91 71 ed 96 8e 4d<br> 1132 : | emitting length of ISAKMP Nonce Payload: 20<br>
[...]<br> 1186 : | IV:<br> 1187 : | d3 dc 05 fb b0 1a ac 23 1a 2b 10 6d a8 81 f6 c3<br> 1188 : | emitting 2 zero bytes of encryption padding into ISAKMP Message<br> 1189 : | encrypting using OAKLEY_3DES_CBC<br>
1190 : | next IV: 00 09 0f dc 66 4a d7 c5<br> 1191 : | emitting length of ISAKMP Message: 308<br> 1192 : | sending 308 bytes for quick_outI1 through eth0:1:500 to xxx.xxx.252.134:500<br>[...]<br> 1271 : "sfr_primary" #1: received and ignored informational message<br>
1272 : | complete state transition with STF_IGNORE<br> 1273 : | next event EVENT_RETRANSMIT in 10 seconds for #2<br> 1274 : |<br> 1275 : | *received 84 bytes from xxx.xxx.252.134:500 on eth0:1 (port=500)<br>[...]<br>
1282 : | **parse ISAKMP Message:<br> 1283 : | initiator cookie:<br> 1284 : | 79 bd de c4 39 d7 41 1d<br> 1285 : | responder cookie:<br> 1286 : | ce df ba 7e 71 c3 1d 16<br> 1287 : | next payload type: ISAKMP_NEXT_HASH<br>
1288 : | ISAKMP version: ISAKMP Version 1.0<br> 1289 : | exchange type: ISAKMP_XCHG_INFO<br> 1290 : | flags: ISAKMP_FLAG_ENCRYPTION<br> 1291 : | message ID: 47 5a cf ab<br> 1292 : | length: 84<br>
1293 : | processing packet with exchange type=ISAKMP_XCHG_INFO (5)<br> 1294 : | ICOOKIE: 79 bd de c4 39 d7 41 1d<br> 1295 : | RCOOKIE: ce df ba 7e 71 c3 1d 16<br> 1296 : | peer: 5b 44 fc 86<br> 1297 : | state hash entry 1<br>
1298 : | peer and cookies match on #2, provided msgid 00000000 vs 5c551e99/00000000<br> 1299 : | peer and cookies match on #1, provided msgid 00000000 vs 00000000/00000000<br> 1300 : | p15 state object #1 found, in STATE_MAIN_I4<br>
1301 : | processing connection sfr_primary<br> 1302 : | last Phase 1 IV: ff 75 1f 04 07 7c 55 b0<br> 1303 : | current Phase 1 IV: ff 75 1f 04 07 7c 55 b0<br> 1304 : | computed Phase 2 IV:<br> 1305 : | ca ab a2 d7 a5 c9 da dc 11 2d d8 3d 8d 61 c0 06<br>
1306 : | received encrypted packet from xxx.xxx.252.134:500<br> 1307 : | decrypting 56 bytes using algorithm OAKLEY_3DES_CBC<br> 1308 : | decrypted:<br>[...]<br> 1313 : | next IV: a5 3a 8d 32 4a 05 c6 76<br> 1314 : | np=8 and sd=0x80e1430<br>
1315 : | ***parse ISAKMP Hash Payload:<br> 1316 : | next payload type: ISAKMP_NEXT_N<br> 1317 : | length: 20<br> 1318 : | np=11 and sd=0x80e1454<br> 1319 : | ***parse ISAKMP Notification Payload:<br> 1320 : | next payload type: ISAKMP_NEXT_NONE<br>
1321 : | length: 32<br> 1322 : | DOI: ISAKMP_DOI_IPSEC<br> 1323 : | protocol ID: 3<br> 1324 : | SPI size: 16<br> 1325 : | Notify Message Type: NO_PROPOSAL_CHOSEN<br><br><br><br>Also I've noticed a strange error messages somewhere in the logs (but it's relative to another not-working tunnel) :<br>
<br>Sep 23 15:40:37 tamerlane pluto[9424]: | payload malformed after IV<br>Sep 23 15:40:37 tamerlane pluto[9424]: |<br>Sep 23 15:40:37 tamerlane pluto[9424]: packet from xxx.xxx.174.200:500: sending notification PAYLOAD_MALFORMED to xxx.xxx.174.200:500<br>
Sep 23 15:40:38 tamerlane pluto[9424]: packet from xxx.xxx.174.200:500: not enough room in input packet for ISAKMP Message (remain=0, sd->size=28)<br><br>This tunnel is against a Cisco-unity pix and the message does'nt appear with Linux Openswan U2.4.11/K2.4.12 (klips).<br>
Funny, while googling this last error message, to find myself sending a message to the list in 2006 with an equivalent problem on an older versions :-D ...<br><br>Any idea?<br>Jean-Michel.<br><br></div>