[Openswan Users] compress and esp option problem

Marco Berizzi pupilla at hotmail.com
Wed Nov 30 11:09:36 CET 2005


Paul Wouters wrote:

>On Tue, 29 Nov 2005, Marco Berizzi wrote:
>
> > I have set esp=3des-sha1! and compress=yes in my ipsec.conf, but pluto 
>isn't
> > proposing ipcomp anymore.
> > What should I do for enable ipcomp and force 3des-sha1?
>
>Do not use the "!" syntax, it is obsolete and strict mode is always 
>implied.
>ipcomp is proposed by default if you compiled support for it in. Even with
>compress=no it will still respond to a compress request. compress=no only
>disables the announcing of ip compression.
>
>Can you show me the log on the initiator for the conn with compress=no and
>compress=yes. Please ensure to ipsec auto --replace connname when changing
>this option in between.

This problem isn't as I have described. It is an interop problem with 
racoon. I know, racoon currently isn't able to process ipcomp correctly. 
However here log files. This is the setkey file on the racoon box:

/usr/local/sbin/setkey -c <<EOF
flush;
spdflush;
spdadd 10.1.2.0/24 10.1.1.0/24 any -P out ipsec
    esp/tunnel/172.16.1.247-172.16.1.226/require;

spdadd 10.1.1.0/24 10.1.2.0/24 any -P in ipsec
    esp/tunnel/172.16.1.226-172.16.1.247/require;

EOF

and this is ipsec.conf on the OSW box:

conn racoon
        left=172.16.1.226
        right=172.16.1.247
        leftnexthop=172.16.1.247
        leftsubnet=10.1.1.0/24
        rightsubnet=10.1.2.0/24
        authby=secret
        #leftfirewall=no
        #rightfirewall=no
        auto=add
        pfs=yes
        #esp=3des-md5-96
        #esp=3des-sha1
        compress=yes
        leftrsasigkey=none
        rightrsasigkey=none
        leftid=172.16.1.226
        keyingtries=0
        keylife=40m

The tunnel will not be established and racoon is complaining:

Nov 30 10:39:14 Calimero racoon: DEBUG:  (proto_id=ESP spisize=4 
spi=5c682245 spi_p=00000000 encmode=Tunnel reqid=0:0)
Nov 30 10:39:14 Calimero racoon: DEBUG:   (trns_id=AES encklen=0 
authtype=hmac-sha)
Nov 30 10:39:14 Calimero racoon: DEBUG:   (trns_id=AES encklen=0 
authtype=hmac-md5)
Nov 30 10:39:14 Calimero racoon: DEBUG:   (trns_id=3DES encklen=0 
authtype=hmac-sha)
Nov 30 10:39:14 Calimero racoon: DEBUG:   (trns_id=3DES encklen=0 
authtype=hmac-md5)
Nov 30 10:39:14 Calimero racoon: DEBUG:  (proto_id=IPCOMP spisize=2 
spi=00000b13 spi_p=00000000 encmode=Tunnel reqid=0:0)
Nov 30 10:39:14 Calimero racoon: DEBUG:   (trns_id=DEFLATE)
Nov 30 10:39:14 Calimero racoon: DEBUG: my single bundle:
Nov 30 10:39:14 Calimero racoon: DEBUG:  (proto_id=ESP spisize=4 
spi=00000000 spi_p=00000000 encmode=Tunnel reqid=0:0)
Nov 30 10:39:14 Calimero racoon: DEBUG:   (trns_id=3DES encklen=0 
authtype=hmac-sha)
Nov 30 10:39:14 Calimero racoon: DEBUG: compute IV for phase2

This is pluto log:

  |
  | *received whack message
  | processing connection racoon
  | empty esp_info, returning empty
  | creating state object #1 at 0x80f9bd8
  | processing connection racoon
  | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
  | RCOOKIE:  00 00 00 00  00 00 00 00
  | peer:  ac 10 01 f7
  | state hash entry 25
  | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
  | Queuing pending Quick Mode with 172.16.1.247 "racoon"
  "racoon" #1: initiating Main Mode
  | sending 212 bytes for main_outI1 through eth0:500 to 172.16.1.247:500:
  | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
  | next event EVENT_RETRANSMIT in 10 seconds for #1
  |
  | *received 80 bytes from 172.16.1.247:500 on eth0 (port=500)
  |  processing packet with exchange type=ISAKMP_XCHG_IDPROT (2)
  | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
  | RCOOKIE:  51 07 fc 69  90 8d 65 8b
  | peer:  ac 10 01 f7
  | state hash entry 31
  | state object not found
  | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
  | RCOOKIE:  00 00 00 00  00 00 00 00
  | peer:  ac 10 01 f7
  | state hash entry 25
  | peer and cookies match on #1, provided msgid 00000000 vs 00000000
  | state object #1 found, in STATE_MAIN_I1
  | processing connection racoon
  | started looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
  | actually looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
  | 1: compared PSK 172.16.1.247 to 172.16.1.226 / 172.16.1.247 -> 2
  | 2: compared PSK 172.16.1.226 to 172.16.1.226 / 172.16.1.247 -> 6
  | 3: compared PSK 172.16.1.225 to 172.16.1.226 / 172.16.1.247 -> 6
  | best_match 0>6 best=0x80f9ab0 (line=25)
  | concluding with best_match=6 best=0x80f9ab0 (lineno=25)
  | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
  | asking helper 0 to do build_kenonce op on seq: 1
  | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
  | complete state transition with STF_SUSPEND
  | next event EVENT_SHUNT_SCAN in 53 seconds
! helper -1 doing build_kenonce op id: 1
  | processing connection racoon
  | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
  | RCOOKIE:  00 00 00 00  00 00 00 00
  | peer:  ac 10 01 f7
  | state hash entry 25
  | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
  | RCOOKIE:  51 07 fc 69  90 8d 65 8b
  | peer:  ac 10 01 f7
  | state hash entry 31
  | complete state transition with STF_OK
  "racoon" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
  | sending reply packet to 172.16.1.247:500 (from port=500)
  | sending 180 bytes for STATE_MAIN_I1 through eth0:500 to 
172.16.1.247:500:
  | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
  "racoon" #1: STATE_MAIN_I2: sent MI2, expecting MR2
  | modecfg pull: noquirk policy:push not-client
  | phase 1 is done, looking for phase 1 to unpend
  | next event EVENT_RETRANSMIT in 10 seconds for #1
  |
  | *received 180 bytes from 172.16.1.247:500 on eth0 (port=500)
  |  processing packet with exchange type=ISAKMP_XCHG_IDPROT (2)
  | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
  | RCOOKIE:  51 07 fc 69  90 8d 65 8b
  | peer:  ac 10 01 f7
  | state hash entry 31
  | peer and cookies match on #1, provided msgid 00000000 vs 00000000
  | state object #1 found, in STATE_MAIN_I2
  | processing connection racoon
  | thinking about whether to send my certificate:
  |   I have RSA key: OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
  |   sendcert: CERT_ALWAYSSEND and I did not get a certificate request
  |   so do not send cert.
  "racoon" #1: I did not send a certificate because I do not have one.
  |  I am not sending a certificate request
  | started looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
  | actually looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
  | 1: compared PSK 172.16.1.247 to 172.16.1.226 / 172.16.1.247 -> 2
  | 2: compared PSK 172.16.1.226 to 172.16.1.226 / 172.16.1.247 -> 6
  | 3: compared PSK 172.16.1.225 to 172.16.1.226 / 172.16.1.247 -> 6
  | best_match 0>6 best=0x80f9ab0 (line=25)
  | concluding with best_match=6 best=0x80f9ab0 (lineno=25)
  | complete state transition with STF_OK
  "racoon" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
  | sending reply packet to 172.16.1.247:500 (from port=500)
  | sending 68 bytes for STATE_MAIN_I2 through eth0:500 to 172.16.1.247:500:
  | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
  "racoon" #1: STATE_MAIN_I3: sent MI3, expecting MR3
  | modecfg pull: noquirk policy:push not-client
  | phase 1 is done, looking for phase 1 to unpend
  | next event EVENT_RETRANSMIT in 10 seconds for #1
  |
  | *received 68 bytes from 172.16.1.247:500 on eth0 (port=500)
  |  processing packet with exchange type=ISAKMP_XCHG_IDPROT (2)
  | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
  | RCOOKIE:  51 07 fc 69  90 8d 65 8b
  | peer:  ac 10 01 f7
  | state hash entry 31
  | peer and cookies match on #1, provided msgid 00000000 vs 00000000
  | state object #1 found, in STATE_MAIN_I3
  | processing connection racoon
  "racoon" #1: Main mode peer ID is ID_IPV4_ADDR: '172.16.1.247'
  | complete state transition with STF_OK
  "racoon" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
  | inserting event EVENT_SA_REPLACE, timeout in 2739 seconds for #1
  "racoon" #1: STATE_MAIN_I4: ISAKMP SA established 
{auth=OAKLEY_PRESHARED_KEY cipher=oakley_3des_cbc_192 prf=oakley_sha 
group=modp1024}
  | modecfg pull: noquirk policy:push not-client
  | phase 1 is done, looking for phase 1 to unpend
  | unqueuing pending Quick Mode with 172.16.1.247 "racoon"
  | duplicating state object #1
  | creating state object #2 at 0x80fbb30
  | processing connection racoon
  | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
  | RCOOKIE:  51 07 fc 69  90 8d 65 8b
  | peer:  ac 10 01 f7
  | state hash entry 31
  | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
  "racoon" #2: initiating Quick Mode PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+UP 
{using isakmp#1}
  | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
  | asking helper 0 to do build_kenonce op on seq: 2
  | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #2
  | next event EVENT_SHUNT_SCAN in 53 seconds
  ! helper -1 doing build_kenonce op id: 2
  | processing connection racoon
  | empty esp_info, returning empty
  | generate SPI:  c1 14 88 de
  | sending 404 bytes for quick_outI1 through eth0:500 to 172.16.1.247:500:
  | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #2
  | next event EVENT_RETRANSMIT in 10 seconds for #2
  |
  | *received 68 bytes from 172.16.1.247:500 on eth0 (port=500)
  |  processing packet with exchange type=ISAKMP_XCHG_INFO (5)
  | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
  | RCOOKIE:  51 07 fc 69  90 8d 65 8b
  | peer:  ac 10 01 f7
  | state hash entry 31
  | peer and cookies match on #2, provided msgid 00000000 vs 
5e3f5a99/00000000
  | peer and cookies match on #1, provided msgid 00000000 vs 
00000000/00000000
  | p15 state object #1 found, in STATE_MAIN_I4
  | processing connection racoon
  "racoon" #1: ignoring informational payload, type NO_PROPOSAL_CHOSEN
  | processing informational NO_PROPOSAL_CHOSEN (14)
  "racoon" #1: received and ignored informational message
  | complete state transition with STF_IGNORE
  | next event EVENT_RETRANSMIT in 10 seconds for #2
   |
   | *time to handle event
   | handling event EVENT_RETRANSMIT
   | event after this is EVENT_SHUNT_SCAN in 43 seconds
   | processing connection racoon
   | handling event EVENT_RETRANSMIT for 172.16.1.247 "racoon" #2
   | sending 404 bytes for EVENT_RETRANSMIT through eth0:500 to 
172.16.1.247:500:
   | inserting event EVENT_RETRANSMIT, timeout in 20 seconds for #2
   | next event EVENT_RETRANSMIT in 20 seconds for #2
   |
   | *received 68 bytes from 172.16.1.247:500 on eth0 (port=500)
   |  processing packet with exchange type=ISAKMP_XCHG_INFO (5)
   | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
   | RCOOKIE:  51 07 fc 69  90 8d 65 8b
   | peer:  ac 10 01 f7
   | state hash entry 31
   | peer and cookies match on #2, provided msgid 00000000 vs 
5e3f5a99/00000000
   | peer and cookies match on #1, provided msgid 00000000 vs 
00000000/00000000
   | p15 state object #1 found, in STATE_MAIN_I4
   | processing connection racoon
   "racoon" #1: ignoring informational payload, type NO_PROPOSAL_CHOSEN
   | processing informational NO_PROPOSAL_CHOSEN (14)
   "racoon" #1: received and ignored informational message
   | complete state transition with STF_IGNORE
   | next event EVENT_RETRANSMIT in 20 seconds for #2
    |
    | *time to handle event
    | handling event EVENT_RETRANSMIT
    | event after this is EVENT_SHUNT_SCAN in 23 seconds
    | processing connection racoon
    | handling event EVENT_RETRANSMIT for 172.16.1.247 "racoon" #2
    | sending 404 bytes for EVENT_RETRANSMIT through eth0:500 to 
172.16.1.247:500:
    | inserting event EVENT_RETRANSMIT, timeout in 40 seconds for #2
    | next event EVENT_SHUNT_SCAN in 23 seconds
    |
    | *received 68 bytes from 172.16.1.247:500 on eth0 (port=500)
    |  processing packet with exchange type=ISAKMP_XCHG_INFO (5)
    | ICOOKIE:  cc 03 90 9e  0c 88 6c bc
    | RCOOKIE:  51 07 fc 69  90 8d 65 8b
    | peer:  ac 10 01 f7
    | state hash entry 31
    | peer and cookies match on #2, provided msgid 00000000 vs 
5e3f5a99/00000000
    | peer and cookies match on #1, provided msgid 00000000 vs 
00000000/00000000
    | p15 state object #1 found, in STATE_MAIN_I4
    | processing connection racoon
    "racoon" #1: ignoring informational payload, type NO_PROPOSAL_CHOSEN
    | processing informational NO_PROPOSAL_CHOSEN (14)
    "racoon" #1: received and ignored informational message
    | complete state transition with STF_IGNORE
    | next event EVENT_SHUNT_SCAN in 23 seconds

When I enable esp=3des-sha1 in ipsec.conf:

conn racoon
        left=172.16.1.226
        right=172.16.1.247
        leftnexthop=172.16.1.247
        leftsubnet=10.1.1.0/24
        rightsubnet=10.1.2.0/24
        authby=secret
        #leftfirewall=no
        #rightfirewall=no
        auto=add
        pfs=yes
        #esp=3des-md5-96
        esp=3des-sha1
        compress=yes
        leftrsasigkey=none
        rightrsasigkey=none
        leftid=172.16.1.226
        keyingtries=0
        keylife=40m
        #auth=ah

then the tunnel will established (without ipcomp):

Nov 30 10:41:41 Calimero racoon: DEBUG: peer's single bundle:
Nov 30 10:41:41 Calimero racoon: DEBUG:  (proto_id=ESP spisize=4 
spi=2ea2cba0 spi_p=00000000 encmode=Tunnel reqid=0:0)
Nov 30 10:41:41 Calimero racoon: DEBUG:   (trns_id=3DES encklen=0 
authtype=hmac-sha)
Nov 30 10:41:41 Calimero racoon: DEBUG: my single bundle:
Nov 30 10:41:41 Calimero racoon: DEBUG:  (proto_id=ESP spisize=4 
spi=00000000 spi_p=00000000 encmode=Tunnel reqid=0:0)
Nov 30 10:41:41 Calimero racoon: DEBUG:   (trns_id=3DES encklen=0 
authtype=hmac-sha)
Nov 30 10:41:41 Calimero racoon: DEBUG: matched
Nov 30 10:41:41 Calimero racoon: DEBUG: ===

This is pluto log:

      | *received whack message
      | processing connection racoon
      | kernel_alg_db_new() will return p_new->protoid=3, p_new->trans_cnt=1
      | kernel_alg_db_new()     trans[0]: transid=3, attr_cnt=1, 
attrs[0].type=5, attrs[0].val=2
      | returning new proposal from esp_info
      | creating state object #1 at 0x80fa100
      | processing connection racoon
      | ICOOKIE:  74 1c 8a 31  06 5d a7 e5
      | RCOOKIE:  00 00 00 00  00 00 00 00
      | peer:  ac 10 01 f7
      | state hash entry 4
      | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
      | Queuing pending Quick Mode with 172.16.1.247 "racoon"
      "racoon" #1: initiating Main Mode
      | sending 212 bytes for main_outI1 through eth0:500 to 
172.16.1.247:500:
      | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
      | next event EVENT_RETRANSMIT in 10 seconds for #1
      |
      | *received 80 bytes from 172.16.1.247:500 on eth0 (port=500)
      |  processing packet with exchange type=ISAKMP_XCHG_IDPROT (2)
      | ICOOKIE:  74 1c 8a 31  06 5d a7 e5
      | RCOOKIE:  32 a8 21 d0  78 18 56 f0
      | peer:  ac 10 01 f7
      | state hash entry 11
      | state object not found
      | ICOOKIE:  74 1c 8a 31  06 5d a7 e5
      | RCOOKIE:  00 00 00 00  00 00 00 00
      | peer:  ac 10 01 f7
      | state hash entry 4
      | peer and cookies match on #1, provided msgid 00000000 vs 00000000
      | state object #1 found, in STATE_MAIN_I1
      | processing connection racoon
      | started looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
      | actually looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
      | 1: compared PSK 172.16.1.247 to 172.16.1.226 / 172.16.1.247 -> 2
      | 2: compared PSK 172.16.1.226 to 172.16.1.226 / 172.16.1.247 -> 6
      | 3: compared PSK 172.16.1.225 to 172.16.1.226 / 172.16.1.247 -> 6
      | best_match 0>6 best=0x80f9fd8 (line=25)
      | concluding with best_match=6 best=0x80f9fd8 (lineno=25)
      | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
      | asking helper 0 to do build_kenonce op on seq: 1
      | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
      | complete state transition with STF_SUSPEND
      | next event EVENT_SHUNT_SCAN in 102 seconds
	 ! helper -1 doing build_kenonce op id: 1
      | processing connection racoon
      | ICOOKIE:  74 1c 8a 31  06 5d a7 e5
      | RCOOKIE:  00 00 00 00  00 00 00 00
      | peer:  ac 10 01 f7
      | state hash entry 4
      | ICOOKIE:  74 1c 8a 31  06 5d a7 e5
      | RCOOKIE:  32 a8 21 d0  78 18 56 f0
      | peer:  ac 10 01 f7
      | state hash entry 11
      | complete state transition with STF_OK
      "racoon" #1: transition from state STATE_MAIN_I1 to state 
STATE_MAIN_I2
      | sending reply packet to 172.16.1.247:500 (from port=500)
      | sending 180 bytes for STATE_MAIN_I1 through eth0:500 to 
172.16.1.247:500:
      | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
      "racoon" #1: STATE_MAIN_I2: sent MI2, expecting MR2
      | modecfg pull: noquirk policy:push not-client
      | phase 1 is done, looking for phase 1 to unpend
      | next event EVENT_RETRANSMIT in 10 seconds for #1
      |
      | *received 180 bytes from 172.16.1.247:500 on eth0 (port=500)
      |  processing packet with exchange type=ISAKMP_XCHG_IDPROT (2)
      | ICOOKIE:  74 1c 8a 31  06 5d a7 e5
      | RCOOKIE:  32 a8 21 d0  78 18 56 f0
      | peer:  ac 10 01 f7
      | state hash entry 11
      | peer and cookies match on #1, provided msgid 00000000 vs 00000000
      | state object #1 found, in STATE_MAIN_I2
      | processing connection racoon
      | thinking about whether to send my certificate:
      |   I have RSA key: OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
      |   sendcert: CERT_ALWAYSSEND and I did not get a certificate request
      |   so do not send cert.
      "racoon" #1: I did not send a certificate because I do not have one.
      |  I am not sending a certificate request
      | started looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
      | actually looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
      | 1: compared PSK 172.16.1.247 to 172.16.1.226 / 172.16.1.247 -> 2
      | 2: compared PSK 172.16.1.226 to 172.16.1.226 / 172.16.1.247 -> 6
      | 3: compared PSK 172.16.1.225 to 172.16.1.226 / 172.16.1.247 -> 6
      | best_match 0>6 best=0x80f9fd8 (line=25)
      | concluding with best_match=6 best=0x80f9fd8 (lineno=25)
      | complete state transition with STF_OK
      "racoon" #1: transition from state STATE_MAIN_I2 to state 
STATE_MAIN_I3
      | sending reply packet to 172.16.1.247:500 (from port=500)
      | sending 68 bytes for STATE_MAIN_I2 through eth0:500 to 
172.16.1.247:500:
      | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
      "racoon" #1: STATE_MAIN_I3: sent MI3, expecting MR3
      | modecfg pull: noquirk policy:push not-client
      | phase 1 is done, looking for phase 1 to unpend
      | next event EVENT_RETRANSMIT in 10 seconds for #1
      |
      | *received 68 bytes from 172.16.1.247:500 on eth0 (port=500)
      |  processing packet with exchange type=ISAKMP_XCHG_IDPROT (2)
      | ICOOKIE:  74 1c 8a 31  06 5d a7 e5
      | RCOOKIE:  32 a8 21 d0  78 18 56 f0
      | peer:  ac 10 01 f7
      | state hash entry 11
      | peer and cookies match on #1, provided msgid 00000000 vs 00000000
      | state object #1 found, in STATE_MAIN_I3
      | processing connection racoon
      "racoon" #1: Main mode peer ID is ID_IPV4_ADDR: '172.16.1.247'
      | complete state transition with STF_OK
      "racoon" #1: transition from state STATE_MAIN_I3 to state 
STATE_MAIN_I4
      | inserting event EVENT_SA_REPLACE, timeout in 3060 seconds for #1
      "racoon" #1: STATE_MAIN_I4: ISAKMP SA established 
{auth=OAKLEY_PRESHARED_KEY cipher=oakley_3des_cbc_192 prf=oakley_sha 
group=modp1024}
      | modecfg pull: noquirk policy:push not-client
      | phase 1 is done, looking for phase 1 to unpend
      | unqueuing pending Quick Mode with 172.16.1.247 "racoon"
      | duplicating state object #1
      | creating state object #2 at 0x80fbf88
      | processing connection racoon
      | ICOOKIE:  74 1c 8a 31  06 5d a7 e5
      | RCOOKIE:  32 a8 21 d0  78 18 56 f0
      | peer:  ac 10 01 f7
      | state hash entry 11
      | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
      "racoon" #2: initiating Quick Mode PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+UP 
{using isakmp#1}
      | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
      | asking helper 0 to do build_kenonce op on seq: 2
      | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #2
      | next event EVENT_SHUNT_SCAN in 102 seconds
! helper -1 doing build_kenonce op id: 2
      | processing connection racoon
      | kernel_alg_db_new() will return p_new->protoid=3, p_new->trans_cnt=1
      | kernel_alg_db_new()     trans[0]: transid=3, attr_cnt=1, 
attrs[0].type=5, attrs[0].val=2
      | returning new proposal from esp_info
      | generate SPI:  67 0a a7 0c
      | sending 292 bytes for quick_outI1 through eth0:500 to 
172.16.1.247:500:
      | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #2
      | next event EVENT_RETRANSMIT in 10 seconds for #2
      |
      | *received 292 bytes from 172.16.1.247:500 on eth0 (port=500)
      |  processing packet with exchange type=ISAKMP_XCHG_QUICK (32)
      | ICOOKIE:  74 1c 8a 31  06 5d a7 e5
      | RCOOKIE:  32 a8 21 d0  78 18 56 f0
      | peer:  ac 10 01 f7
      | state hash entry 11
      | peer and cookies match on #2, provided msgid d93067fe vs d93067fe
      | state object #2 found, in STATE_QUICK_I1
      | processing connection racoon
      | started looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
      | actually looking for secret for 172.16.1.226->172.16.1.247 of kind 
PPK_PSK
      | 1: compared PSK 172.16.1.247 to 172.16.1.226 / 172.16.1.247 -> 2
      | 2: compared PSK 172.16.1.226 to 172.16.1.226 / 172.16.1.247 -> 6
      | 3: compared PSK 172.16.1.225 to 172.16.1.226 / 172.16.1.247 -> 6
      | best_match 0>6 best=0x80f9fd8 (line=25)
      | concluding with best_match=6 best=0x80f9fd8 (lineno=25)
      | our client is subnet 10.1.1.0/24
      | our client protocol/port is 0/0
      | peer client is subnet 10.1.2.0/24
      | peer client protocol/port is 0/0
      | install_ipsec_sa() for #2: inbound and outbound
      | route owner of "racoon" unrouted: NULL; eroute owner: NULL
      | could_route called for racoon (kind=CK_PERMANENT)
      | add inbound eroute 10.1.2.0/24:0 --0-> 10.1.1.0/24:0 => 
tun.1001 at 172.16.1.226 (raw_eroute)
      | sr for #2: unrouted
      | route owner of "racoon" unrouted: NULL; eroute owner: NULL
      | eroute_connection add eroute 10.1.1.0/24:0 --0-> 10.1.2.0/24:0 => 
tun.1002 at 172.16.1.247 (raw_eroute)
      | command executing up-client
      | executing up-client: 2>&1 PLUTO_VERSION='1.1' PLUTO_VERB='up-client' 
PLUTO_CONNECTION='racoon' PLUTO_NEXT_HOP='172.16.1.247' 
PLUTO_INTERFACE='ipsec0' PLUTO_ME='172.16.1.226' PLUTO_MY_ID='172.16.1.226' 
PLUTO_MY_CLIENT='10.1.1.0/24' PLUTO_MY_CLIENT_NET='10.1.1.0' 
PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' 
PLUTO_PEER='172.16.1.247' PLUTO_PEER_ID='172.16.1.247' 
PLUTO_PEER_CLIENT='10.1.2.0/24' PLUTO_PEER_CLIENT_NET='10.1.2.0' 
PLUTO_PEER_CLIENT_MASK='255.255.255.0' PLUTO_PEER_PORT='0' 
PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' 
PLUTO_CONN_POLICY='PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+UP'   ipsec _updown
      | route_and_eroute: firewall_notified: true
      | command executing prepare-client
      | executing prepare-client: 2>&1 PLUTO_VERSION='1.1' 
PLUTO_VERB='prepare-client' PLUTO_CONNECTION='racoon' 
PLUTO_NEXT_HOP='172.16.1.247' PLUTO_INTERFACE='ipsec0' 
PLUTO_ME='172.16.1.226' PLUTO_MY_ID='172.16.1.226' 
PLUTO_MY_CLIENT='10.1.1.0/24' PLUTO_MY_CLIENT_NET='10.1.1.0' 
PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' 
PLUTO_PEER='172.16.1.247' PLUTO_PEER_ID='172.16.1.247' 
PLUTO_PEER_CLIENT='10.1.2.0/24' PLUTO_PEER_CLIENT_NET='10.1.2.0' 
PLUTO_PEER_CLIENT_MASK='255.255.255.0' PLUTO_PEER_PORT='0' 
PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' 
PLUTO_CONN_POLICY='PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+UP'   ipsec _updown
      | command executing route-client
      | executing route-client: 2>&1 PLUTO_VERSION='1.1' 
PLUTO_VERB='route-client' PLUTO_CONNECTION='racoon' 
PLUTO_NEXT_HOP='172.16.1.247' PLUTO_INTERFACE='ipsec0' 
PLUTO_ME='172.16.1.226' PLUTO_MY_ID='172.16.1.226' 
PLUTO_MY_CLIENT='10.1.1.0/24' PLUTO_MY_CLIENT_NET='10.1.1.0' 
PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' 
PLUTO_PEER='172.16.1.247' PLUTO_PEER_ID='172.16.1.247' 
PLUTO_PEER_CLIENT='10.1.2.0/24' PLUTO_PEER_CLIENT_NET='10.1.2.0' 
PLUTO_PEER_CLIENT_MASK='255.255.255.0' PLUTO_PEER_PORT='0' 
PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' 
PLUTO_CONN_POLICY='PSK+ENCRYPT+COMPRESS+TUNNEL+PFS+UP'   ipsec _updown
      | route_and_eroute: instance "racoon", setting eroute_owner 
{spd=0x80f955c,sr=0x80f955c} to #2 (was #0) (newest_ipsec_sa=#0)
      | complete state transition with STF_OK
      "racoon" #2: transition from state STATE_QUICK_I1 to state 
STATE_QUICK_I2
      | sending reply packet to 172.16.1.247:500 (from port=500)
      | sending 52 bytes for STATE_QUICK_I1 through eth0:500 to 
172.16.1.247:500:
      | inserting event EVENT_SA_REPLACE, timeout in 1605 seconds for #2
      "racoon" #2: STATE_QUICK_I2: sent QI2, IPsec SA established 
{ESP=>0x043875eb <0x670aa70c xfrm=3DES_0-HMAC_SHA1 NATD=none DPD=none}
      | modecfg pull: noquirk policy:push not-client
      | phase 1 is done, looking for phase 1 to unpend
      | next event EVENT_SHUNT_SCAN in 102 seconds




More information about the Users mailing list