Package: racoon Version: 1:0.6.6-3.1etch1 Severity: important Sometimes it takes two weeks the problem occurs or like today, it took about 4 hours after the reboot of the IPSec gateway. The IPSec tunnel is between Cisco and Debian Etch. It was working more than 1 year between Cisco and Sarge, but after clean upgrade (reinstalled) from Sarge to Etch this problem occured.
cisco ~ aa.aa.aa.aa Etch ~ bb.bb.bb.bb Syslog: Oct 16 12:25:07 rtr1 racoon: DEBUG: get pfkey EXPIRE message Oct 16 12:25:07 rtr1 racoon: INFO: IPsec-SA expired: ESP/Tunnel aa.aa.aa.aa[0]->bb.bb.bb.bb[0] spi=41261448(0x2759988) Oct 16 12:25:08 rtr1 racoon: DEBUG: get pfkey EXPIRE message Oct 16 12:25:08 rtr1 racoon: INFO: IPsec-SA expired: ESP/Tunnel bb.bb.bb.bb[0]->aa.aa.aa.aa[0] spi=3194968428(0xbe6f596c) Oct 16 12:25:08 rtr1 racoon: DEBUG: no such a SA found: ESP/Tunnel bb.bb.bb.bb[0]->aa.aa.aa.aa[0] spi=3194968428(0xbe6f596c) Oct 16 12:26:56 rtr1 racoon: DEBUG: === Oct 16 12:26:56 rtr1 racoon: DEBUG: 76 bytes message received from aa.aa.aa.aa[500] to bb.bb.bb.bb[500] Oct 16 12:26:56 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 ef4373fb 0000004c fbc4e737 f7f45b8e 602d54bb 41c8a23e 668ed030 87829e8f e1655ce4 2d8c6d38 2bcaf606 f93d694b 15cef1e8 38a8d7b9 Oct 16 12:26:56 rtr1 racoon: DEBUG: receive Information. Oct 16 12:26:56 rtr1 racoon: DEBUG: compute IV for phase2 Oct 16 12:26:56 rtr1 racoon: DEBUG: phase1 last IV: Oct 16 12:26:56 rtr1 racoon: DEBUG: 3da4ce95 28d76516 ef4373fb Oct 16 12:26:56 rtr1 racoon: DEBUG: hash(sha1) Oct 16 12:26:56 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:26:56 rtr1 racoon: DEBUG: phase2 IV computed: Oct 16 12:26:56 rtr1 racoon: DEBUG: 77d4981d 7b4c882e Oct 16 12:26:56 rtr1 racoon: DEBUG: begin decryption. Oct 16 12:26:56 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:26:56 rtr1 racoon: DEBUG: IV was saved for next processing: Oct 16 12:26:56 rtr1 racoon: DEBUG: 15cef1e8 38a8d7b9 Oct 16 12:26:56 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:26:56 rtr1 racoon: DEBUG: with key: Oct 16 12:26:56 rtr1 racoon: DEBUG: 4dd5ba3c 522ed6e5 ea8ec433 31556686 298cf19d 9baadef9 Oct 16 12:26:56 rtr1 racoon: DEBUG: decrypted payload by IV: Oct 16 12:26:56 rtr1 racoon: DEBUG: 77d4981d 7b4c882e Oct 16 12:26:56 rtr1 racoon: DEBUG: decrypted payload, but not trimed. Oct 16 12:26:56 rtr1 racoon: DEBUG: 0c000018 03cc5583 de63cf31 9b9e63e0 409cfd85 1559476a 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:26:56 rtr1 racoon: DEBUG: padding len=1 Oct 16 12:26:56 rtr1 racoon: DEBUG: skip to trim padding. Oct 16 12:26:56 rtr1 racoon: DEBUG: decrypted. Oct 16 12:26:56 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 ef4373fb 0000004c 0c000018 03cc5583 de63cf31 9b9e63e0 409cfd85 1559476a 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:26:56 rtr1 racoon: DEBUG: HASH with: Oct 16 12:26:56 rtr1 racoon: DEBUG: ef4373fb 00000010 00000001 03040001 98e953f6 Oct 16 12:26:56 rtr1 racoon: DEBUG: hmac(hmac_sha1) Oct 16 12:26:56 rtr1 racoon: DEBUG: HASH computed: Oct 16 12:26:56 rtr1 racoon: DEBUG: 03cc5583 de63cf31 9b9e63e0 409cfd85 1559476a Oct 16 12:26:56 rtr1 racoon: DEBUG: hash validated. Oct 16 12:26:56 rtr1 racoon: DEBUG: begin. Oct 16 12:26:56 rtr1 racoon: DEBUG: seen nptype=8(hash) Oct 16 12:26:56 rtr1 racoon: DEBUG: seen nptype=12(delete) Oct 16 12:26:56 rtr1 racoon: DEBUG: succeed. Oct 16 12:26:56 rtr1 racoon: DEBUG: Cannot record event: event queue overflowed Oct 16 12:26:56 rtr1 racoon: DEBUG: call pfkey_send_dump Oct 16 12:26:56 rtr1 racoon: DEBUG: purged SAs. Oct 16 12:27:07 rtr1 racoon: DEBUG: === Oct 16 12:27:07 rtr1 racoon: DEBUG: 76 bytes message received from aa.aa.aa.aa[500] to bb.bb.bb.bb[500] Oct 16 12:27:07 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 41554808 0000004c 4b23cea6 07dc46dc 97f9a856 42917199 1d84971d b6ae1e25 66f72380 1c3a3940 8a60ff5e bf46605f ad881659 e3892095 Oct 16 12:27:07 rtr1 racoon: DEBUG: receive Information. Oct 16 12:27:07 rtr1 racoon: DEBUG: compute IV for phase2 Oct 16 12:27:07 rtr1 racoon: DEBUG: phase1 last IV: Oct 16 12:27:07 rtr1 racoon: DEBUG: 3da4ce95 28d76516 41554808 Oct 16 12:27:07 rtr1 racoon: DEBUG: hash(sha1) Oct 16 12:27:07 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:07 rtr1 racoon: DEBUG: phase2 IV computed: Oct 16 12:27:07 rtr1 racoon: DEBUG: 4aaa78dc 6a306112 Oct 16 12:27:07 rtr1 racoon: DEBUG: begin decryption. Oct 16 12:27:07 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:07 rtr1 racoon: DEBUG: IV was saved for next processing: Oct 16 12:27:07 rtr1 racoon: DEBUG: ad881659 e3892095 Oct 16 12:27:07 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:07 rtr1 racoon: DEBUG: with key: Oct 16 12:27:07 rtr1 racoon: DEBUG: 4dd5ba3c 522ed6e5 ea8ec433 31556686 298cf19d 9baadef9 Oct 16 12:27:07 rtr1 racoon: DEBUG: decrypted payload by IV: Oct 16 12:27:07 rtr1 racoon: DEBUG: 4aaa78dc 6a306112 Oct 16 12:27:07 rtr1 racoon: DEBUG: decrypted payload, but not trimed. Oct 16 12:27:07 rtr1 racoon: DEBUG: 0c000018 9ed85916 37662b58 d1f2e30b e46d35fa 2dbd2c65 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:27:07 rtr1 racoon: DEBUG: padding len=1 Oct 16 12:27:07 rtr1 racoon: DEBUG: skip to trim padding. Oct 16 12:27:07 rtr1 racoon: DEBUG: decrypted. Oct 16 12:27:07 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 41554808 0000004c 0c000018 9ed85916 37662b58 d1f2e30b e46d35fa 2dbd2c65 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:27:07 rtr1 racoon: DEBUG: HASH with: Oct 16 12:27:07 rtr1 racoon: DEBUG: 41554808 00000010 00000001 03040001 98e953f6 Oct 16 12:27:07 rtr1 racoon: DEBUG: hmac(hmac_sha1) Oct 16 12:27:07 rtr1 racoon: DEBUG: HASH computed: Oct 16 12:27:07 rtr1 racoon: DEBUG: 9ed85916 37662b58 d1f2e30b e46d35fa 2dbd2c65 Oct 16 12:27:07 rtr1 racoon: DEBUG: hash validated. Oct 16 12:27:07 rtr1 racoon: DEBUG: begin. Oct 16 12:27:07 rtr1 racoon: DEBUG: seen nptype=8(hash) Oct 16 12:27:07 rtr1 racoon: DEBUG: seen nptype=12(delete) Oct 16 12:27:07 rtr1 racoon: DEBUG: succeed. Oct 16 12:27:07 rtr1 racoon: DEBUG: Cannot record event: event queue overflowed Oct 16 12:27:07 rtr1 racoon: DEBUG: call pfkey_send_dump Oct 16 12:27:07 rtr1 racoon: DEBUG: purged SAs. Oct 16 12:27:17 rtr1 racoon: DEBUG: === Oct 16 12:27:17 rtr1 racoon: DEBUG: 76 bytes message received from aa.aa.aa.aa[500] to bb.bb.bb.bb[500] Oct 16 12:27:17 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 968287e1 0000004c 28626ab3 6cdca187 74c4fd5a b16f411b 5ff44eae 5a898222 770a94d6 e96b0e82 a8f3f01f c7d8e4a4 7b957e2b 8e69e3ae Oct 16 12:27:17 rtr1 racoon: DEBUG: receive Information. Oct 16 12:27:17 rtr1 racoon: DEBUG: compute IV for phase2 Oct 16 12:27:17 rtr1 racoon: DEBUG: phase1 last IV: Oct 16 12:27:17 rtr1 racoon: DEBUG: 3da4ce95 28d76516 968287e1 Oct 16 12:27:17 rtr1 racoon: DEBUG: hash(sha1) Oct 16 12:27:17 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:17 rtr1 racoon: DEBUG: phase2 IV computed: Oct 16 12:27:17 rtr1 racoon: DEBUG: a021a3c4 69b7a52b Oct 16 12:27:17 rtr1 racoon: DEBUG: begin decryption. Oct 16 12:27:17 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:17 rtr1 racoon: DEBUG: IV was saved for next processing: Oct 16 12:27:17 rtr1 racoon: DEBUG: 7b957e2b 8e69e3ae Oct 16 12:27:17 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:17 rtr1 racoon: DEBUG: with key: Oct 16 12:27:17 rtr1 racoon: DEBUG: 4dd5ba3c 522ed6e5 ea8ec433 31556686 298cf19d 9baadef9 Oct 16 12:27:17 rtr1 racoon: DEBUG: decrypted payload by IV: Oct 16 12:27:17 rtr1 racoon: DEBUG: a021a3c4 69b7a52b Oct 16 12:27:17 rtr1 racoon: DEBUG: decrypted payload, but not trimed. Oct 16 12:27:17 rtr1 racoon: DEBUG: 0c000018 18919a90 25350318 c5d5405f a7c8a545 d6d1572e 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:27:17 rtr1 racoon: DEBUG: padding len=1 Oct 16 12:27:17 rtr1 racoon: DEBUG: skip to trim padding. Oct 16 12:27:17 rtr1 racoon: DEBUG: decrypted. Oct 16 12:27:17 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 968287e1 0000004c 0c000018 18919a90 25350318 c5d5405f a7c8a545 d6d1572e 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:27:17 rtr1 racoon: DEBUG: HASH with: Oct 16 12:27:17 rtr1 racoon: DEBUG: 968287e1 00000010 00000001 03040001 98e953f6 Oct 16 12:27:17 rtr1 racoon: DEBUG: hmac(hmac_sha1) Oct 16 12:27:17 rtr1 racoon: DEBUG: HASH computed: Oct 16 12:27:17 rtr1 racoon: DEBUG: 18919a90 25350318 c5d5405f a7c8a545 d6d1572e Oct 16 12:27:17 rtr1 racoon: DEBUG: hash validated. Oct 16 12:27:17 rtr1 racoon: DEBUG: begin. Oct 16 12:27:17 rtr1 racoon: DEBUG: seen nptype=8(hash) Oct 16 12:27:17 rtr1 racoon: DEBUG: seen nptype=12(delete) Oct 16 12:27:17 rtr1 racoon: DEBUG: succeed. Oct 16 12:27:17 rtr1 racoon: DEBUG: Cannot record event: event queue overflowed Oct 16 12:27:17 rtr1 racoon: DEBUG: call pfkey_send_dump Oct 16 12:27:17 rtr1 racoon: DEBUG: purged SAs. Oct 16 12:27:23 rtr1 racoon: DEBUG: === Oct 16 12:27:23 rtr1 racoon: DEBUG: 76 bytes message received from aa.aa.aa.aa[500] to bb.bb.bb.bb[500] Oct 16 12:27:23 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 cba935ad 0000004c 774eb61b 533fed21 e5e76b78 c412a36b 9e79f903 ba7755b1 93bc914e 5cd0d766 9ef09307 8e39eba6 8de810b0 7bb068a4 Oct 16 12:27:23 rtr1 racoon: DEBUG: receive Information. Oct 16 12:27:23 rtr1 racoon: DEBUG: compute IV for phase2 Oct 16 12:27:23 rtr1 racoon: DEBUG: phase1 last IV: Oct 16 12:27:23 rtr1 racoon: DEBUG: 3da4ce95 28d76516 cba935ad Oct 16 12:27:23 rtr1 racoon: DEBUG: hash(sha1) Oct 16 12:27:23 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:23 rtr1 racoon: DEBUG: phase2 IV computed: Oct 16 12:27:23 rtr1 racoon: DEBUG: 3e6a8dda 6747344a Oct 16 12:27:23 rtr1 racoon: DEBUG: begin decryption. Oct 16 12:27:23 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:23 rtr1 racoon: DEBUG: IV was saved for next processing: Oct 16 12:27:23 rtr1 racoon: DEBUG: 8de810b0 7bb068a4 Oct 16 12:27:23 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:23 rtr1 racoon: DEBUG: with key: Oct 16 12:27:23 rtr1 racoon: DEBUG: 4dd5ba3c 522ed6e5 ea8ec433 31556686 298cf19d 9baadef9 Oct 16 12:27:23 rtr1 racoon: DEBUG: decrypted payload by IV: Oct 16 12:27:23 rtr1 racoon: DEBUG: 3e6a8dda 6747344a Oct 16 12:27:23 rtr1 racoon: DEBUG: decrypted payload, but not trimed. Oct 16 12:27:23 rtr1 racoon: DEBUG: 0c000018 926c95bf 70035d4d 9ed02bfe 18e5638e a7e9b1f2 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:27:23 rtr1 racoon: DEBUG: padding len=1 Oct 16 12:27:23 rtr1 racoon: DEBUG: skip to trim padding. Oct 16 12:27:23 rtr1 racoon: DEBUG: decrypted. Oct 16 12:27:23 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 cba935ad 0000004c 0c000018 926c95bf 70035d4d 9ed02bfe 18e5638e a7e9b1f2 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:27:23 rtr1 racoon: DEBUG: HASH with: Oct 16 12:27:23 rtr1 racoon: DEBUG: cba935ad 00000010 00000001 03040001 98e953f6 Oct 16 12:27:23 rtr1 racoon: DEBUG: hmac(hmac_sha1) Oct 16 12:27:23 rtr1 racoon: DEBUG: HASH computed: Oct 16 12:27:23 rtr1 racoon: DEBUG: 926c95bf 70035d4d 9ed02bfe 18e5638e a7e9b1f2 Oct 16 12:27:23 rtr1 racoon: DEBUG: hash validated. Oct 16 12:27:23 rtr1 racoon: DEBUG: begin. Oct 16 12:27:23 rtr1 racoon: DEBUG: seen nptype=8(hash) Oct 16 12:27:23 rtr1 racoon: DEBUG: seen nptype=12(delete) Oct 16 12:27:23 rtr1 racoon: DEBUG: succeed. Oct 16 12:27:23 rtr1 racoon: DEBUG: Cannot record event: event queue overflowed Oct 16 12:27:23 rtr1 racoon: DEBUG: call pfkey_send_dump Oct 16 12:27:23 rtr1 racoon: DEBUG: purged SAs. Oct 16 12:27:56 rtr1 racoon: DEBUG: === Oct 16 12:27:56 rtr1 racoon: DEBUG: 76 bytes message received from aa.aa.aa.aa[500] to bb.bb.bb.bb[500] Oct 16 12:27:56 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 6b4b1ae1 0000004c 266544f0 4c803499 700c810a aa5caf9d 9a2fa111 51cf85d9 609d8d4d 45ec5668 d90223ac b02e3c62 3fed089b c6db0762 Oct 16 12:27:56 rtr1 racoon: DEBUG: receive Information. Oct 16 12:27:56 rtr1 racoon: DEBUG: compute IV for phase2 Oct 16 12:27:56 rtr1 racoon: DEBUG: phase1 last IV: Oct 16 12:27:56 rtr1 racoon: DEBUG: 3da4ce95 28d76516 6b4b1ae1 Oct 16 12:27:56 rtr1 racoon: DEBUG: hash(sha1) Oct 16 12:27:56 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:56 rtr1 racoon: DEBUG: phase2 IV computed: Oct 16 12:27:56 rtr1 racoon: DEBUG: 05172c49 e62bbf45 Oct 16 12:27:56 rtr1 racoon: DEBUG: begin decryption. Oct 16 12:27:56 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:56 rtr1 racoon: DEBUG: IV was saved for next processing: Oct 16 12:27:56 rtr1 racoon: DEBUG: 3fed089b c6db0762 Oct 16 12:27:56 rtr1 racoon: DEBUG: encryption(3des) Oct 16 12:27:56 rtr1 racoon: DEBUG: with key: Oct 16 12:27:56 rtr1 racoon: DEBUG: 4dd5ba3c 522ed6e5 ea8ec433 31556686 298cf19d 9baadef9 Oct 16 12:27:56 rtr1 racoon: DEBUG: decrypted payload by IV: Oct 16 12:27:56 rtr1 racoon: DEBUG: 05172c49 e62bbf45 Oct 16 12:27:56 rtr1 racoon: DEBUG: decrypted payload, but not trimed. Oct 16 12:27:56 rtr1 racoon: DEBUG: 0c000018 600a9fbf 03899b26 475492e5 0a6122e4 1c7e7081 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:27:56 rtr1 racoon: DEBUG: padding len=1 Oct 16 12:27:56 rtr1 racoon: DEBUG: skip to trim padding. Oct 16 12:27:56 rtr1 racoon: DEBUG: decrypted. Oct 16 12:27:56 rtr1 racoon: DEBUG: 33afe426 d17334b3 06f20708 5a70e0d2 08100501 6b4b1ae1 0000004c 0c000018 600a9fbf 03899b26 475492e5 0a6122e4 1c7e7081 00000010 00000001 03040001 98e953f6 00000000 00000000 Oct 16 12:27:56 rtr1 racoon: DEBUG: HASH with: Oct 16 12:27:56 rtr1 racoon: DEBUG: 6b4b1ae1 00000010 00000001 03040001 98e953f6 Oct 16 12:27:56 rtr1 racoon: DEBUG: hmac(hmac_sha1) Oct 16 12:27:56 rtr1 racoon: DEBUG: HASH computed: Oct 16 12:27:56 rtr1 racoon: DEBUG: 600a9fbf 03899b26 475492e5 0a6122e4 1c7e7081 Oct 16 12:27:56 rtr1 racoon: DEBUG: hash validated. Oct 16 12:27:56 rtr1 racoon: DEBUG: begin. Oct 16 12:27:56 rtr1 racoon: DEBUG: seen nptype=8(hash) Oct 16 12:27:56 rtr1 racoon: DEBUG: seen nptype=12(delete) Oct 16 12:27:56 rtr1 racoon: DEBUG: succeed. Oct 16 12:27:56 rtr1 racoon: DEBUG: Cannot record event: event queue overflowed Oct 16 12:27:56 rtr1 racoon: DEBUG: call pfkey_send_dump Oct 16 12:27:56 rtr1 racoon: DEBUG: purged SAs. If I run "/etc/init.d/racoon restart" everything works fine for week or day or hours... racoon.conf: path pre_shared_key "/etc/racoon/psk.txt"; log debug; timer { phase1 60 sec; phase2 60 sec; } listen { isakmp bb.bb.bb.bb; } remote aa.aa.aa.aa { exchange_mode main; proposal { encryption_algorithm 3des; hash_algorithm sha1; authentication_method pre_shared_key; dh_group modp1024; } generate_policy off; lifetime time 86400 sec; dpd_delay 10; dpd_retry 5; dpd_maxfail 2; } sainfo address 192.168.1.0/24 any address 192.168.32.0/24 any { pfs_group modp1536; encryption_algorithm 3des; authentication_algorithm hmac_sha1; compression_algorithm deflate; } ipsec-tools.conf: #!/usr/sbin/setkey -f flush; spdflush; spdadd 192.168.1.0/24 192.168.32.0/24 any -P out ipsec esp/tunnel/bb.bb.bb.bb-aa.aa.aa.aa/unique; spdadd 192.168.32.0/24 192.168.1.0/24 any -P in ipsec esp/tunnel/aa.aa.aa.aa-bb.bb.bb.bb/unique; -- System Information: Debian Release: 4.0 APT prefers stable APT policy: (500, 'stable') Architecture: i386 (i686) Shell: /bin/sh linked to /bin/bash Kernel: Linux 2.6.18-5-686 Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8) Versions of packages racoon depends on: ii debconf 1.5.11 Debian configuration management sy ii ipsec-to 1:0.6.6-3.1etch1 IPsec tools for Linux ii libc6 2.3.6.ds1-13etch2 GNU C Library: Shared libraries ii libcomer 1.39+1.40-WIP-2006.11.14+dfsg-2 common error description library ii libkrb53 1.4.4-7etch4 MIT Kerberos runtime libraries ii libpam0g 0.79-4 Pluggable Authentication Modules l ii libssl0. 0.9.8c-4etch1 SSL shared libraries ii perl 5.8.8-7 Larry Wall's Practical Extraction racoon recommends no packages. -- debconf information: * racoon/config_mode: direct -- To UNSUBSCRIBE, email to [EMAIL PROTECTED] with a subject of "unsubscribe". Trouble? Contact [EMAIL PROTECTED]