I'm testing ipsec-tools 0.7.3 with an Avaya 4620sw IP/vpn phone in hopes of eventually replacing a Netgear FVS336G vpn gateway a customer is now using for their VOIP traffic.
The phone currently establishes an vpn connection and can download files from its TFTP server in the protected LAN. However, when it tries to log into its callserver (the analog of the old PBX) and sends its first packet, it loses the vpn. It tries to re-establish it, appears to get it back for a second and then loses it again. This continues on ad infinitum. The IPSec log shows little. It looks as though the tunnel is established, but then the incoming association is immediately deleted. The SPDs remain in place and are correct, but the SAD from the client to the server is replicated over and over again. I breadboarded the IPSec parameters with a Shrew Soft client and this doesn't happen with it. Is this surmountable or is it just possibly just incompatible with the IPSec implementation on the phone? I'm no IPSec expert, but I have have set up tunnels in the past and have never encountered this before. Does anyone have an idea of what is happening or am I hooped?
Here are some details, including the IPSec log:
- the phone is set to negotiate as much of the the IPSec parameters itself.
- the server is set to P1- 3DES/MD5, P2 - all/MD5.
- the dh group is the same on both ends. PFS is off on both ends
- I can supply more information as required if anyone needs it.
In the following, 11.11.11.11 represents the server's public address; 22.22.22.22 is the phone's public address:
IPSec log:
The above will continue to recycle ad nauseum.
The phone currently establishes an vpn connection and can download files from its TFTP server in the protected LAN. However, when it tries to log into its callserver (the analog of the old PBX) and sends its first packet, it loses the vpn. It tries to re-establish it, appears to get it back for a second and then loses it again. This continues on ad infinitum. The IPSec log shows little. It looks as though the tunnel is established, but then the incoming association is immediately deleted. The SPDs remain in place and are correct, but the SAD from the client to the server is replicated over and over again. I breadboarded the IPSec parameters with a Shrew Soft client and this doesn't happen with it. Is this surmountable or is it just possibly just incompatible with the IPSec implementation on the phone? I'm no IPSec expert, but I have have set up tunnels in the past and have never encountered this before. Does anyone have an idea of what is happening or am I hooped?
Here are some details, including the IPSec log:
- the phone is set to negotiate as much of the the IPSec parameters itself.
- the server is set to P1- 3DES/MD5, P2 - all/MD5.
- the dh group is the same on both ends. PFS is off on both ends
- I can supply more information as required if anyone needs it.
In the following, 11.11.11.11 represents the server's public address; 22.22.22.22 is the phone's public address:
Code:
SADs:
Source Destination Protocol SPI Enc.alg. Auth.alg.
11.11.11.11[4500] 22.22.22.22[3215] ESP-UDP b14f57a8 aes-cbc hmac-md5
22.22.22.22[3215] 11.11.11.11[4500] ESP-UDP 0645f011 aes-cbc hmac-md5
22.22.22.22[3215] 11.11.11.11[4500] ESP-UDP 01bde4de aes-cbc hmac-md5
SPDs:
Source Destination Direction Protocol Tunnel endpoints
10.10.90.1 192.168.43.0/24 -> ESP 22.22.22.22 -> 11.11.11.11
192.168.43.0/24 10.10.90.1 <- ESP 11.11.11.11 -> 22.22.22.22IPSec log:
Code:
Feb 2 22:02:27 gw2 racoon: DEBUG: pfkey UPDATE succeeded: ESP 22.22.22.22[3215]->11.11.11.11[4500]
spi=29222110(0x1bde4de)
Feb 2 22:02:27 gw2 racoon: INFO: IPsec-SA established: ESP 22.22.22.22[3215]->11.11.11.11[4500]
spi=29222110(0x1bde4de)
Feb 2 22:02:27 gw2 racoon: DEBUG: ===
Feb 2 22:02:27 gw2 racoon: DEBUG: pk_recv: retry[0] recv()
Feb 2 22:02:27 gw2 racoon: DEBUG: get pfkey ADD message
Feb 2 22:02:27 gw2 racoon: INFO: IPsec-SA established: ESP 11.11.11.11[4500]->22.22.22.22[3215]
spi=2014875735(0x78189057)
Feb 2 22:02:27 gw2 racoon: DEBUG: ===
Feb 2 22:02:27 gw2 racoon: DEBUG: pk_recv: retry[0] recv()
Feb 2 22:02:27 gw2 racoon: DEBUG: get pfkey X_SPDUPDATE message
Feb 2 22:02:27 gw2 racoon: DEBUG: sub:0xbfbfe6a4: 10.10.90.1/32[0] 192.168.43.0/24[0] proto=any dir=in
Feb 2 22:02:27 gw2 racoon: DEBUG: db :0x28548148: 192.168.43.0/24[0] 192.168.43.1/32[0] proto=any dir=in
Feb 2 22:02:27 gw2 racoon: DEBUG: sub:0xbfbfe6a4: 10.10.90.1/32[0] 192.168.43.0/24[0] proto=any dir=in
Feb 2 22:02:27 gw2 racoon: DEBUG: db :0x28548288: 192.168.43.1/32[0] 192.168.43.0/24[0] proto=any
dir=out
Feb 2 22:02:27 gw2 racoon: ERROR: such policy does not already exist: "10.10.90.1/32[0]
192.168.43.0/24[0] proto=any dir=in"
Feb 2 22:02:27 gw2 racoon: DEBUG: pk_recv: retry[0] recv()
Feb 2 22:02:27 gw2 racoon: DEBUG: get pfkey X_SPDUPDATE message
Feb 2 22:02:27 gw2 racoon: DEBUG: sub:0xbfbfe6a4: 192.168.43.0/24[0] 10.10.90.1/32[0] proto=any dir=out
Feb 2 22:02:27 gw2 racoon: DEBUG: db :0x28548148: 192.168.43.0/24[0] 192.168.43.1/32[0] proto=any dir=in
Feb 2 22:02:27 gw2 racoon: DEBUG: sub:0xbfbfe6a4: 192.168.43.0/24[0] 10.10.90.1/32[0] proto=any dir=out
Feb 2 22:02:27 gw2 racoon: DEBUG: db :0x28548288: 192.168.43.1/32[0] 192.168.43.0/24[0] proto=any
dir=out
Feb 2 22:02:27 gw2 racoon: DEBUG: sub:0xbfbfe6a4: 192.168.43.0/24[0] 10.10.90.1/32[0] proto=any dir=out
Feb 2 22:02:27 gw2 racoon: DEBUG: db :0x28548648: 10.10.90.1/32[0] 192.168.43.0/24[0] proto=any dir=in
Feb 2 22:02:27 gw2 racoon: ERROR: such policy does not already exist: "192.168.43.0/24[0]
10.10.90.1/32[0] proto=any dir=out"
Feb 2 22:04:06 gw2 racoon: DEBUG: ===
Feb 2 22:04:06 gw2 racoon: DEBUG: 530 bytes message received from 22.22.22.22[3215] to 11.11.11.11[4500]
Feb 2 22:04:06 gw2 racoon: DEBUG: 4e6c469a 20f26cbf 00000000 00000000 01100400 00000000 00000212
040000d4 00000001 00000001 000000c8 05010005 03000028 01010000 80010007 800e0080 80020001 80040002
80030001 800b0001 000c0004 00069780 03000024 02010000 80010005 80020001 80040002 80030001 800b0001
000c0004 00069780 03000024 03010000 80010001 80020001 80040002 80030001 800b0001 000c0004 00069780
03000028 04010000 80010007 800e00c0 80020001 80040002 80030001 800b0001 000c0004 00069780 00000028
05010000 80010007 800e0100 80020001 80040002 80030001 800b0001 000c0004 00069780 0a000084 74506318
4763c2c2 2f11907d 082941e1 4260b235 d49849b9 cfa81198 a904ad3f 9c4ff638 c036c804 68e447ea 4facc1b8
8ef41d84 15f8e4e9 e5b2f163
1a05a95a 5f559f83 47694e4b a5f0f719 917b0886 bc4d0581 abe162da b2a0ed98 3c82fdc9 4dc60a47 91977f88
836b1107 7558903f 0f1d805b 7dcf140d 73d85718 e93c2074 05000018 e32fe6de 7afe05c7 6eada339 a3345714
d6012229 0d000016 02000000 32342d37 70686f6e 65732e63 6f6d0d00 00144a13 1c810703 58455c57 28f20e95 452f0d
Feb 2 22:04:06 gw2 racoon: DEBUG: anonymous configuration selected for 22.22.22.22.
Feb 2 22:04:06 gw2 racoon: DEBUG: Marking ports as changed
Feb 2 22:04:06 gw2 racoon: DEBUG: ===
Feb 2 22:04:06 gw2 racoon: INFO: respond new phase 1 negotiation: 11.11.11.11[4500]<=>22.22.22.22[3215]
Feb 2 22:04:06 gw2 racoon: INFO: begin Aggressive mode.
Feb 2 22:04:06 gw2 racoon: DEBUG: begin.The above will continue to recycle ad nauseum.