I am trying to set up a host-to-host connection between my CentOS 5 box and a Windows 2003 server using a PSK. I am getting the following error messages in my racoon.log file: 2009-05-04 07:43:27: INFO: @(#)ipsec-tools 0.6.5 (http://ipsec-tools.sourceforge.net) 2009-05-04 07:43:27: INFO: @(#)This product linked OpenSSL 0.9.8e-fips-rhel5 01 Jul 2008 (http://www.openssl.org/) 2009-05-04 07:43:27: DEBUG: call pfkey_send_register for AH 2009-05-04 07:43:27: DEBUG: call pfkey_send_register for ESP 2009-05-04 07:43:27: DEBUG: call pfkey_send_register for IPCOMP 2009-05-04 07:43:27: DEBUG: reading config file /etc/racoon/racoon.conf 2009-05-04 07:43:27: DEBUG2: lifetime = 28800 2009-05-04 07:43:27: DEBUG2: lifebyte = 0 2009-05-04 07:43:27: DEBUG2: encklen=0 2009-05-04 07:43:27: DEBUG2: p:1 t:1 2009-05-04 07:43:27: DEBUG2: 3DES-CBC(5) 2009-05-04 07:43:27: DEBUG2: SHA(2) 2009-05-04 07:43:27: DEBUG2: 2048-bit MODP group(14) 2009-05-04 07:43:27: DEBUG2: pre-shared key(1) 2009-05-04 07:43:27: DEBUG2: 2009-05-04 07:43:27: DEBUG: compression algorithm can not be checked because sadb message doesn't support it. 2009-05-04 07:43:27: DEBUG: filename: /etc/racoon/x.x.x.x.conf 2009-05-04 07:43:27: DEBUG: reading config file /etc/racoon/x.x.x.x.conf 2009-05-04 07:43:27: DEBUG2: lifetime = 28800 2009-05-04 07:43:27: DEBUG2: lifebyte = 0 2009-05-04 07:43:27: DEBUG2: encklen=0 2009-05-04 07:43:27: DEBUG2: p:1 t:1 2009-05-04 07:43:27: DEBUG2: 3DES-CBC(5) 2009-05-04 07:43:27: DEBUG2: SHA(2) 2009-05-04 07:43:27: DEBUG2: 1024-bit MODP group(2) 2009-05-04 07:43:27: DEBUG2: pre-shared key(1) 2009-05-04 07:43:27: DEBUG2: 2009-05-04 07:43:27: DEBUG: hmac(modp1024) 2009-05-04 07:43:27: DEBUG2: parse successed. 2009-05-04 07:43:27: DEBUG: open /var/racoon/racoon.sock as racoon management. 2009-05-04 07:43:27: DEBUG: my interface: fe80::213:72ff:fe93:9d31%eth0 (eth0) 2009-05-04 07:43:27: DEBUG: my interface: ::1 (lo) 2009-05-04 07:43:27: DEBUG: my interface: x.x.x.x (eth0) 2009-05-04 07:43:27: DEBUG: my interface: 127.0.0.1 (lo) 2009-05-04 07:43:27: DEBUG: configuring default isakmp port. 2009-05-04 07:43:27: DEBUG: 4 addrs are configured successfully 2009-05-04 07:43:27: ERROR: failed to bind to address 127.0.0.1[500] (Address already in use). 2009-05-04 07:43:27: ERROR: failed to bind to address x.x.x.x [500] (Address already in use). 2009-05-04 07:43:27: ERROR: failed to bind to address ::1[500] (Address already in use). 2009-05-04 07:43:27: ERROR: failed to bind to address fe80::213:72ff:fe93:9d31%eth0[500] (Address already in use). 2009-05-04 07:43:27: ERROR: no address could be bound. Any ideas what could be causing this? Thanks, Chris
Some other daemon is already listening to the socket UDP 500, run Code: netstat -nulp to see what it is.
Thanks. I killed the process that was listening on port 500. that solved the issue of racoon being unable to bind the port. Now, think the two are not negotiating correctly. I am getting the error messages below. Code: 2009-05-06 03:57:07: DEBUG: suitable outbound SP found: x.x.x.x/32[0] x.x.x.x/32[0] proto=any dir=out. 2009-05-06 03:57:07: DEBUG: sub:0xbfbc2d78: x.x.x.x/32[0] x.x.x.x/32[0] proto=any dir=in 2009-05-06 03:57:07: DEBUG: db :0x8721a10: x.x.x.x/32[0] x.x.x.x/32[0] proto=any dir=out 2009-05-06 03:57:07: DEBUG: sub:0xbfbc2d78: x.x.x.x/32[0] x.x.x.x/32[0] proto=any dir=in 2009-05-06 03:57:07: DEBUG: db :0x8722960: x.x.x.x/32[0] x.x.x.x/32[0] proto=any dir=in 2009-05-06 03:57:07: DEBUG: suitable inbound SP found: x.x.x.x/32[0] x.x.x.x/32[0] proto=any dir=in. 2009-05-06 03:57:07: DEBUG: new acquire x.x.x.x/32[0] x.x.x.x/32[0] proto=any dir=out 2009-05-06 03:57:07: DEBUG: anonymous sainfo selected. 2009-05-06 03:57:07: DEBUG: (proto_id=AH spisize=4 spi=00000000 spi_p=00000000 encmode=Transport reqid=0:0) 2009-05-06 03:57:07: DEBUG: (trns_id=SHA authtype=hmac-sha) 2009-05-06 03:57:07: DEBUG: (trns_id=MD5 authtype=hmac-md5) 2009-05-06 03:57:07: DEBUG: (proto_id=ESP spisize=4 spi=00000000 spi_p=00000000 encmode=Transport reqid=0:0) 2009-05-06 03:57:07: DEBUG: (trns_id=3DES encklen=0 authtype=hmac-sha) 2009-05-06 03:57:07: DEBUG: (trns_id=3DES encklen=0 authtype=hmac-md5) 2009-05-06 03:57:07: DEBUG: (trns_id=BLOWFISH encklen=448 authtype=hmac-sha) 2009-05-06 03:57:07: DEBUG: (trns_id=BLOWFISH encklen=448 authtype=hmac-md5) 2009-05-06 03:57:07: DEBUG: (trns_id=AES encklen=128 authtype=hmac-sha) 2009-05-06 03:57:07: DEBUG: (trns_id=AES encklen=128 authtype=hmac-md5) 2009-05-06 03:57:07: DEBUG: configuration found for x.x.x.x. 2009-05-06 03:57:07: INFO: request for establishing IPsec-SA was queued due to no phase1 found. 2009-05-06 03:57:07: DEBUG: 264 bytes from x.x.x.x[500] to x.x.x.x[500] 2009-05-06 03:57:07: DEBUG: sockname x.x.x.x[500] 2009-05-06 03:57:07: DEBUG: send packet from x.x.x.x[500] 2009-05-06 03:57:07: DEBUG: send packet to x.x.x.x[500] 2009-05-06 03:57:07: DEBUG: src4 x.x.x.x[500] 2009-05-06 03:57:07: DEBUG: dst4 x.x.x.x[500] 2009-05-06 03:57:07: DEBUG: 1 times of 264 bytes message will be sent to x.x.x.x[500] 2009-05-06 03:57:07: DEBUG: 466bd9ff 422cdf20 00000000 00000000 01100400 00000000 00000108 04000034 00000001 00000001 00000028 01010001 00000020 01010000 800b0001 800c7080 80010005 80030001 80020002 80040002 0a000084 358a8bdb 33934615 771a5878 b61d9439 6f101927 126293ba 42f9b29f e18486b9 8b1ccaa0 21fcccbb ca56562a 552cc204 81d3b58b 44a42a05 d326ef7c 1dbba264 b98ad84b 62280dda 58cfa4bf 859252e2 e9290bff 485a156b 132661fc c9e563a6 8832de63 2023dcaa ba9ff8ba 43568016 4cb15298 2936fe8c 1e86fec5 e46060c1 05000014 c6fcbd09 95599ee1 5de53525 e766dccd 0d00000c 011101f4 0aa46838 00000014 afcad713 68a1f1c9 6b8696fc 77570100 2009-05-06 03:57:07: DEBUG: resend phase1 packet 466bd9ff422cdf20:0000000000000000 2009-05-06 03:57:08: ERROR: phase2 negotiation failed due to time up waiting for phase1. ESP x.x.x.x[500]->x.x.x.x[500] 2009-05-06 03:57:08: INFO: delete phase 2 handler. 2009-05-06 03:59:00: INFO: unsupported PF_KEY message REGISTER 2009-05-06 03:59:00: DEBUG: get pfkey X_SPDDELETE2 message
The peer is the Windows host. I have it configured to 3DES on the Confidentiality and SHA1 on the Integrity and again they are set to use the same PSK. Do you think I am missing some configuration there? Below is the peer conf file in Racoon for the Windows host. Thanks for all your help. Code: remote x.x.x.x { exchange_mode aggressive, main; my_identifier address; proposal { encryption_algorithm 3des; hash_algorithm sha1; authentication_method pre_shared_key; dh_group 2; } }
I have worked with some of the configurations and am now getting the following in my racoon log file. Code: unknown notify message, no phase2 handle found. notification message 14:NO-PROPOSAL-CHOSEN, doi=1 proto_id=3 spi=00000000(size=4)
That means phase1 (isakmp) negotiation succeeded but phase2 (ipsec) failed, you need to check that what you propose to the pear matches what is configured on your side.
Thanks for your help with this. I have checked to make sure they are the same and I believe that they are. My config for phase2 is the following: Code: sainfo anonymous { pfs_group 1; lifetime time 1 hour ; encryption_algorithm 3des ; authentication_algorithm hmac_sha1 ; compression_algorithm deflate ; } and a larger segment of my racoon log is below: Code: 2009-05-07 07:35:23: DEBUG: resend phase2 packet f54d366ed36ce644:2de9980389e965e9:0000ad9a 2009-05-07 07:35:23: DEBUG: === 2009-05-07 07:35:23: DEBUG: 84 bytes message received from x.x.x.x[500] to y.y.y.y[500] 2009-05-07 07:35:23: DEBUG: f54d366e d36ce644 2de99803 89e965e9 08100501 9fb60b70 00000054 113631e6 38cafe2d 31f87370 1a9620bd 1e10b463 f0197c28 400cb2b7 c377b3f7 a3c9de20 6f0a0493 f9e2f519 93621694 7ed2621a 757628a8 2009-05-07 07:35:23: DEBUG: receive Information. 2009-05-07 07:35:23: DEBUG: compute IV for phase2 2009-05-07 07:35:23: DEBUG: phase1 last IV: 2009-05-07 07:35:23: DEBUG: 4cf18a29 f2c522c8 9fb60b70 2009-05-07 07:35:23: DEBUG: hash(sha1) 2009-05-07 07:35:23: DEBUG: encryption(3des) 2009-05-07 07:35:23: DEBUG: phase2 IV computed: 2009-05-07 07:35:23: DEBUG: 0a00831a 843719b9 2009-05-07 07:35:23: DEBUG: begin decryption. 2009-05-07 07:35:23: DEBUG: encryption(3des) 2009-05-07 07:35:23: DEBUG: IV was saved for next processing: 2009-05-07 07:35:23: DEBUG: 7ed2621a 757628a8 2009-05-07 07:35:23: DEBUG: encryption(3des) 2009-05-07 07:35:23: DEBUG: with key: 2009-05-07 07:35:23: DEBUG: 8106a255 f5e03200 25b2aec1 32f4913f fe03d39b 69c8711a 2009-05-07 07:35:23: DEBUG: decrypted payload by IV: 2009-05-07 07:35:23: DEBUG: 0a00831a 843719b9 2009-05-07 07:35:23: DEBUG: decrypted payload, but not trimed. 2009-05-07 07:35:23: DEBUG: 0b000018 2fccb0e9 7ffbc1d3 82b3486c b7f85248 da1ce9e1 0000001c 00000001 0304000e 00000000 0a005c00 01000000 01000000 00000000 2009-05-07 07:35:23: DEBUG: padding len=1 2009-05-07 07:35:23: DEBUG: skip to trim padding. 2009-05-07 07:35:23: DEBUG: decrypted. 2009-05-07 07:35:23: DEBUG: f54d366e d36ce644 2de99803 89e965e9 08100501 9fb60b70 00000054 0b000018 2fccb0e9 7ffbc1d3 82b3486c b7f85248 da1ce9e1 0000001c 00000001 0304000e 00000000 0a005c00 01000000 01000000 00000000 2009-05-07 07:35:23: DEBUG: HASH with: 2009-05-07 07:35:23: DEBUG: 9fb60b70 0000001c 00000001 0304000e 00000000 0a005c00 01000000 01000000 2009-05-07 07:35:23: DEBUG: hmac(hmac_sha1) 2009-05-07 07:35:23: DEBUG: HASH computed: 2009-05-07 07:35:23: DEBUG: 2fccb0e9 7ffbc1d3 82b3486c b7f85248 da1ce9e1 2009-05-07 07:35:23: DEBUG: hash validated. 2009-05-07 07:35:23: DEBUG: begin. 2009-05-07 07:35:23: DEBUG: seen nptype=8(hash) 2009-05-07 07:35:23: DEBUG: seen nptype=11(notify) 2009-05-07 07:35:23: DEBUG: succeed. 2009-05-07 07:35:23: ERROR: unknown notify message, no phase2 handle found. 2009-05-07 07:35:23: DEBUG: notification message 14:NO-PROPOSAL-CHOSEN, doi=1 proto_id=3 spi=00000000(size=4). 2009-05-07 07:35:23: DEBUG: get pfkey EXPIRE message 2009-05-07 07:35:23: INFO: IPsec-SA expired: AH/Transport x.x.x.x[0]->y.y.y.y[0] spi=208723548(0xc70de5c) 2009-05-07 07:35:23: DEBUG: no such a SA found: AH/Transport x.x.x.x[0]->y.y.y.y[0] spi=208723548(0xc70de5c) 2009-05-07 07:35:23: DEBUG: get pfkey EXPIRE message 2009-05-07 07:35:23: INFO: IPsec-SA expired: ESP/Transport x.x.x.x[0]->y.y.y.y[0] spi=207127279(0xc5882ef) 2009-05-07 07:35:23: DEBUG: no such a SA found: ESP/Transport x.x.x.x[0]->y.y.y.y[0] spi=207127279(0xc5882ef)
Where 'x.x.x.x' is the CentOS host, and 'y.y.y.y' and 'z.z.z.z' are the IP addresses of the Windows box. Code: spdadd x.x.x.x/32 y.y.y.y/32 any -P out ipsec esp/transport//require ah/transport//require; spdadd y.y.y.y/32 x.x.x.x/32 any -P in ipsec esp/transport//require ah/transport//require; spdadd x.x.x.x/32 z.z.z.z/32 any -P out ipsec esp/transport//require ah/transport//require; spdadd z.z.z.z/32 x.x.x.x/32 any -P in ipsec esp/transport//require ah/transport//require;
It could be the pfs_group, any why i have not used windows as a node before only as a road warrior so beyond what i can pick up from the logs i can not say. Look at the logs on the windows side as well and see why it is rejecting the proposal.
