[Openswan Users] Another attempt to get connected to a SonicWALL VPN.

Bas Driessen bas.driessen at xobas.com
Wed Nov 22 23:23:38 EST 2006 

Hello,

I have a Linux Desktop PC that I need to connect to a SonicWALL VPN. The
linux PC has an ip number of 192.168.1.13 and is connected to the
Internet via gateway 192.168.1.1. The VPN server where I need to connect
to has an IP number of 66.nnn.nnn.nnn (for obvious security reasons I am
using nnn here) and this connects to subnet 192.168.128.0/24. So in
fact, I am just trying to create a VPN client to server connection.

The details that I got from the system admin who maintains the VPN is
that it is using the following:

- SonicWALL VPN
- ESP 3DES HMAC MD5 (IKE) 
- XAUTH authentication is not required.


My configuration is as follows:

/etc/ipsec.d/sonicwall.conf

conn sonicwall
    type=tunnel
    auto=add
    auth=esp
    pfs=yes
    authby=secret
    keyingtries=1
    left=192.168.1.13
    leftsubnet=192.168.1.13/32
    right=66.nnn.nnn.nnn
    rightsubnet=192.168.128.0/24
    rightid=66.nnn.nnn.nnn
    esp=3des-md5
    keyexchange=ike
    ike=3des-md5

/etc/ipsec.d/sonicwall.secrets

192.168.1.13 66.nnn.nnn.nnn : PSK "somesecretkeyphrase"

When starting the ipsec service (/etc/rc.d/init.d/ipsec start), the
output to screen as follows:

[root at ams ipsec.d]# /sbin/service ipsec restart
Shutting down IPsec:  Stopping Openswan IPsec...
                                                           [  OK  ]
Starting IPsec:  Starting Openswan IPsec 2.4.5...
insmod /lib/modules/2.6.18-1.2849.fc6/kernel/net/key/af_key.ko 
insmod /lib/modules/2.6.18-1.2849.fc6/kernel/net/ipv4/xfrm4_tunnel.ko 
                                                           [  OK  ]
[root at ams ipsec.d]# 


The output in /var/log/messages:

Nov 23 14:05:43 ams kernel: NET: Registered protocol family 15
Nov 23 14:05:43 ams ipsec_setup: KLIPS ipsec0 on eth0
192.168.1.13/255.255.255.0 broadcast 192.168.1.255 
Nov 23 14:05:44 ams ipsec_setup: ...Openswan IPsec started


The output in /var/log/secure:

Nov 23 14:06:36 ams ipsec__plutorun: Starting Pluto subsystem...
Nov 23 14:06:36 ams pluto[16213]: Starting Pluto (Openswan Version 2.4.5
X.509-1.5.4 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR; Vendor ID OEnMCu
\177xOp at c)
Nov 23 14:06:36 ams pluto[16213]: Setting NAT-Traversal port-4500
floating to on
Nov 23 14:06:36 ams pluto[16213]:    port floating activation criteria
nat_t=1/port_fload=1
Nov 23 14:06:36 ams pluto[16213]:   including NAT-Traversal patch
(Version 0.6c)
Nov 23 14:06:36 ams pluto[16213]: | opening /dev/urandom
Nov 23 14:06:36 ams pluto[16213]: | inserting event EVENT_REINIT_SECRET,
timeout in 3600 seconds
Nov 23 14:06:36 ams pluto[16213]: | inserting event
EVENT_PENDING_PHASE2, timeout in 120 seconds
Nov 23 14:06:36 ams pluto[16213]: ike_alg_register_enc(): Activating
OAKLEY_AES_CBC: Ok (ret=0)
Nov 23 14:06:36 ams pluto[16213]: starting up 1 cryptographic helpers
Nov 23 14:06:36 ams pluto[16214]: | opening /dev/urandom
Nov 23 14:06:36 ams pluto[16213]: started helper pid=16214 (fd:6)
Nov 23 14:06:36 ams pluto[16213]: Using Linux 2.6 IPsec interface code
on 2.6.18-1.2849.fc6
Nov 23 14:06:36 ams pluto[16213]: Could not change to directory
'/etc/ipsec.d/cacerts'
Nov 23 14:06:36 ams pluto[16213]: Could not change to directory
'/etc/ipsec.d/aacerts'
Nov 23 14:06:36 ams pluto[16213]: Could not change to directory
'/etc/ipsec.d/ocspcerts'
Nov 23 14:06:36 ams pluto[16213]: Could not change to directory
'/etc/ipsec.d/crls'
Nov 23 14:06:36 ams pluto[16213]: | inserting event EVENT_LOG_DAILY,
timeout in 35604 seconds
Nov 23 14:06:36 ams pluto[16213]: | next event EVENT_PENDING_PHASE2 in
120 seconds
Nov 23 14:06:36 ams pluto[16214]: ! helper 0 waiting on fd: 7
Nov 23 14:06:36 ams pluto[16213]: |  
Nov 23 14:06:36 ams pluto[16213]: | *received whack message
Nov 23 14:06:36 ams pluto[16213]: | Added new connection sonicwall with
policy PSK+ENCRYPT+TUNNEL+PFS
Nov 23 14:06:36 ams pluto[16213]: | from whack: got --esp=3des-md5
Nov 23 14:06:36 ams pluto[16213]: | esp string values: 3_000-1,
flags=strict
Nov 23 14:06:36 ams pluto[16213]: | from whack: got --ike=3des-md5
Nov 23 14:06:36 ams pluto[16213]: | ike string values: 5_000-1-5,
5_000-1-2, flags=strict
Nov 23 14:06:36 ams pluto[16213]: | counting wild cards for (none) is 15
Nov 23 14:06:36 ams pluto[16213]: | counting wild cards for
66.nnn.nnn.nnn is 0
Nov 23 14:06:36 ams pluto[16213]: | alg_info_addref()
alg_info->ref_cnt=1
Nov 23 14:06:36 ams pluto[16213]: | alg_info_addref()
alg_info->ref_cnt=1
Nov 23 14:06:36 ams pluto[16213]: | alg_info_addref()
alg_info->ref_cnt=2
Nov 23 14:06:36 ams pluto[16213]: | alg_info_addref()
alg_info->ref_cnt=2
Nov 23 14:06:36 ams pluto[16213]: added connection description
"sonicwall"
Nov 23 14:06:36 ams pluto[16213]: |
192.168.1.13/32===192.168.1.13...66.nnn.nnn.nnn===192.168.128.0/24
Nov 23 14:06:36 ams pluto[16213]: | ike_life: 3600s; ipsec_life: 28800s;
rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 1; policy: PSK
+ENCRYPT+TUNNEL+PFS
Nov 23 14:06:36 ams pluto[16213]: | next event EVENT_PENDING_PHASE2 in
120 seconds
Nov 23 14:06:36 ams pluto[16213]: |  
Nov 23 14:06:36 ams pluto[16213]: | *received whack message
Nov 23 14:06:36 ams pluto[16213]: listening for IKE messages
Nov 23 14:06:36 ams pluto[16213]: | found lo with address 127.0.0.1
Nov 23 14:06:36 ams pluto[16213]: | found eth0 with address 192.168.1.13
Nov 23 14:06:36 ams pluto[16213]: adding interface eth0/eth0
192.168.1.13:500
Nov 23 14:06:36 ams pluto[16213]: adding interface eth0/eth0
192.168.1.13:4500
Nov 23 14:06:36 ams pluto[16213]: adding interface lo/lo 127.0.0.1:500
Nov 23 14:06:36 ams pluto[16213]: adding interface lo/lo 127.0.0.1:4500
Nov 23 14:06:36 ams pluto[16213]: | found lo with address
0000:0000:0000:0000:0000:0000:0000:0001
Nov 23 14:06:36 ams pluto[16213]: adding interface lo/lo ::1:500
Nov 23 14:06:36 ams pluto[16213]: loading secrets from
"/etc/ipsec.secrets"
Nov 23 14:06:36 ams pluto[16213]: loading secrets from
"/etc/ipsec.d/hostkey.secrets"
Nov 23 14:06:36 ams pluto[16213]: | loaded private key for keyid:
PPK_RSA:AQOQ1MmLS
Nov 23 14:06:36 ams pluto[16213]: loading secrets from
"/etc/ipsec.d/sonicwall.secrets"
Nov 23 14:06:36 ams pluto[16213]: | next event EVENT_PENDING_PHASE2 in
120 seconds

When trying to create the connection, I type:

/usr/sbin/ipsec whack --name sonicwall --initiate

The output to screen is:

[root at ams ipsec.d]# /usr/sbin/ipsec whack --name sonicwall --initiate
002 "sonicwall" #1: initiating Main Mode
104 "sonicwall" #1: STATE_MAIN_I1: initiate
010 "sonicwall" #1: STATE_MAIN_I1: retransmission; will wait 20s for
response

(the re-transmission errors are repeating)

The output in /var/log/secret:

Nov 23 14:09:54 ams pluto[16661]: |  
Nov 23 14:09:54 ams pluto[16661]: | *received whack message
Nov 23 14:09:54 ams pluto[16661]: | processing connection sonicwall
Nov 23 14:09:54 ams pluto[16661]: | kernel_alg_db_new() will return
p_new->protoid=3, p_new->trans_cnt=1
Nov 23 14:09:54 ams pluto[16661]: | kernel_alg_db_new()     trans[0]:
transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
Nov 23 14:09:54 ams pluto[16661]: | returning new proposal from esp_info
Nov 23 14:09:54 ams pluto[16661]: | creating state object #1 at
0x55555581f330
Nov 23 14:09:54 ams pluto[16661]: | processing connection sonicwall
Nov 23 14:09:54 ams pluto[16661]: | ICOOKIE:  b3 fb 6d de  b8 44 10 98
Nov 23 14:09:54 ams pluto[16661]: | RCOOKIE:  00 00 00 00  00 00 00 00
Nov 23 14:09:54 ams pluto[16661]: | peer:  42 b4 67 52
Nov 23 14:09:54 ams pluto[16661]: | state hash entry 0
Nov 23 14:09:54 ams pluto[16661]: | inserting event EVENT_SO_DISCARD,
timeout in 0 seconds for #1
Nov 23 14:09:54 ams pluto[16661]: | Queuing pending Quick Mode with
66.nnn.nnn.nnn "sonicwall"
Nov 23 14:09:54 ams pluto[16661]: "sonicwall" #1: initiating Main Mode
Nov 23 14:09:54 ams pluto[16661]: | sending 248 bytes for main_outI1
through eth0:500 to 66.nnn.nnn.nnn:500:
Nov 23 14:09:54 ams pluto[16661]: | inserting event EVENT_RETRANSMIT,
timeout in 10 seconds for #1
Nov 23 14:09:54 ams pluto[16661]: | next event EVENT_RETRANSMIT in 10
seconds for #1
Nov 23 14:09:54 ams pluto[16661]: |  
Nov 23 14:09:54 ams pluto[16661]: | *received 92 bytes from
66.nnn.nnn.nnn:500 on eth0 (port=500)
Nov 23 14:09:54 ams pluto[16661]: | **parse ISAKMP Message:
Nov 23 14:09:54 ams pluto[16661]: |    initiator cookie:
Nov 23 14:09:54 ams pluto[16661]: |   b3 fb 6d de  b8 44 10 98
Nov 23 14:09:54 ams pluto[16661]: |    responder cookie:
Nov 23 14:09:54 ams pluto[16661]: |   4b c1 9a fa  48 f0 0d 6d
Nov 23 14:09:54 ams pluto[16661]: |    next payload type: ISAKMP_NEXT_N
Nov 23 14:09:54 ams pluto[16661]: |    ISAKMP version: ISAKMP Version
1.0
Nov 23 14:09:54 ams pluto[16661]: |    exchange type: ISAKMP_XCHG_INFO
Nov 23 14:09:54 ams pluto[16661]: |    flags: none
Nov 23 14:09:54 ams pluto[16661]: |    message ID:  00 00 00 00
Nov 23 14:09:54 ams pluto[16661]: |    length: 92
Nov 23 14:09:54 ams pluto[16661]: |  processing packet with exchange
type=ISAKMP_XCHG_INFO (5)
Nov 23 14:09:54 ams pluto[16661]: | ICOOKIE:  b3 fb 6d de  b8 44 10 98
Nov 23 14:09:54 ams pluto[16661]: | RCOOKIE:  4b c1 9a fa  48 f0 0d 6d
Nov 23 14:09:54 ams pluto[16661]: | peer:  42 b4 67 52
Nov 23 14:09:54 ams pluto[16661]: | state hash entry 14
Nov 23 14:09:54 ams pluto[16661]: | p15 state object not found
Nov 23 14:09:54 ams pluto[16661]: | ***parse ISAKMP Notification
Payload:
Nov 23 14:09:54 ams pluto[16661]: |    next payload type:
ISAKMP_NEXT_NONE
Nov 23 14:09:54 ams pluto[16661]: |    length: 64
Nov 23 14:09:54 ams pluto[16661]: |    DOI: ISAKMP_DOI_ISAKMP
Nov 23 14:09:54 ams pluto[16661]: |    protocol ID: 1
Nov 23 14:09:54 ams pluto[16661]: |    SPI size: 16
Nov 23 14:09:54 ams pluto[16661]: |    Notify Message Type:
NO_PROPOSAL_CHOSEN
Nov 23 14:09:54 ams pluto[16661]: packet from 66.nnn.nnn.nnn:500:
ignoring informational payload, type NO_PROPOSAL_CHOSEN
Nov 23 14:09:54 ams pluto[16661]: | info:  b3 fb 6d de  b8 44 10 98  4b
c1 9a fa  48 f0 0d 6d
Nov 23 14:09:54 ams pluto[16661]: |   00 06 00 04  00 00 00 00  00 04 00
18  00 00 00 4e
Nov 23 14:09:54 ams pluto[16661]: |   6f 20 70 72  6f 70 6f 73  61 6c 20
69  73 20 63 68
Nov 23 14:09:54 ams pluto[16661]: |   6f 73 65 6e
Nov 23 14:09:54 ams pluto[16661]: | processing informational
NO_PROPOSAL_CHOSEN (14)
Nov 23 14:09:54 ams pluto[16661]: packet from 66.nnn.nnn.nnn:500:
received and ignored informational message
Nov 23 14:09:54 ams pluto[16661]: | complete state transition with
STF_IGNORE
Nov 23 14:09:54 ams pluto[16661]: | next event EVENT_RETRANSMIT in 10
seconds for #1
^[[5~Nov 23 14:10:04 ams pluto[16661]: |  
Nov 23 14:10:04 ams pluto[16661]: | *time to handle event
Nov 23 14:10:04 ams pluto[16661]: | handling event EVENT_RETRANSMIT
Nov 23 14:10:04 ams pluto[16661]: | event after this is
EVENT_PENDING_PHASE2 in 103 seconds
Nov 23 14:10:04 ams pluto[16661]: | processing connection sonicwall
Nov 23 14:10:04 ams pluto[16661]: | handling event EVENT_RETRANSMIT for
66.nnn.nnn.nnn "sonicwall" #1
Nov 23 14:10:04 ams pluto[16661]: | sending 248 bytes for
EVENT_RETRANSMIT through eth0:500 to 66.nnn.nnn.nnn:500:
Nov 23 14:10:04 ams pluto[16661]: | inserting event EVENT_RETRANSMIT,
timeout in 20 seconds for #1
Nov 23 14:10:04 ams pluto[16661]: | next event EVENT_RETRANSMIT in 20
seconds for #1
Nov 23 14:10:05 ams pluto[16661]: |  
Nov 23 14:10:05 ams pluto[16661]: | *received 92 bytes from
66.nnn.nnn.nnn:500 on eth0 (port=500)
Nov 23 14:10:05 ams pluto[16661]: | **parse ISAKMP Message:
Nov 23 14:10:05 ams pluto[16661]: |    initiator cookie:
Nov 23 14:10:05 ams pluto[16661]: |   b3 fb 6d de  b8 44 10 98
Nov 23 14:10:05 ams pluto[16661]: |    responder cookie:
Nov 23 14:10:05 ams pluto[16661]: |   47 fd ab 64  42 c5 bd b5
Nov 23 14:10:05 ams pluto[16661]: |    next payload type: ISAKMP_NEXT_N
Nov 23 14:10:05 ams pluto[16661]: |    ISAKMP version: ISAKMP Version
1.0
Nov 23 14:10:05 ams pluto[16661]: |    exchange type: ISAKMP_XCHG_INFO
Nov 23 14:10:05 ams pluto[16661]: |    flags: none
Nov 23 14:10:05 ams pluto[16661]: |    message ID:  00 00 00 00
Nov 23 14:10:05 ams pluto[16661]: |    length: 92
Nov 23 14:10:05 ams pluto[16661]: |  processing packet with exchange
type=ISAKMP_XCHG_INFO (5)
Nov 23 14:10:05 ams pluto[16661]: | ICOOKIE:  b3 fb 6d de  b8 44 10 98
Nov 23 14:10:05 ams pluto[16661]: | RCOOKIE:  47 fd ab 64  42 c5 bd b5
Nov 23 14:10:05 ams pluto[16661]: | peer:  42 b4 67 52
Nov 23 14:10:05 ams pluto[16661]: | state hash entry 18
Nov 23 14:10:05 ams pluto[16661]: | p15 state object not found
Nov 23 14:10:05 ams pluto[16661]: | ***parse ISAKMP Notification
Payload:
Nov 23 14:10:05 ams pluto[16661]: |    next payload type:
ISAKMP_NEXT_NONE
Nov 23 14:10:05 ams pluto[16661]: |    length: 64
Nov 23 14:10:05 ams pluto[16661]: |    DOI: ISAKMP_DOI_ISAKMP
Nov 23 14:10:05 ams pluto[16661]: |    protocol ID: 1
Nov 23 14:10:05 ams pluto[16661]: |    SPI size: 16
Nov 23 14:10:05 ams pluto[16661]: |    Notify Message Type:
NO_PROPOSAL_CHOSEN
Nov 23 14:10:05 ams pluto[16661]: packet from 66.nnn.nnn.nnn:500:
ignoring informational payload, type NO_PROPOSAL_CHOSEN
Nov 23 14:10:05 ams pluto[16661]: | info:  b3 fb 6d de  b8 44 10 98  47
fd ab 64  42 c5 bd b5
Nov 23 14:10:05 ams pluto[16661]: |   00 06 00 04  00 00 00 00  00 04 00
18  00 00 00 4e
Nov 23 14:10:05 ams pluto[16661]: |   6f 20 70 72  6f 70 6f 73  61 6c 20
69  73 20 63 68
Nov 23 14:10:05 ams pluto[16661]: |   6f 73 65 6e
Nov 23 14:10:05 ams pluto[16661]: | processing informational
NO_PROPOSAL_CHOSEN (14)
Nov 23 14:10:05 ams pluto[16661]: packet from 66.nnn.nnn.nnn:500:
received and ignored informational message
Nov 23 14:10:05 ams pluto[16661]: | complete state transition with
STF_IGNORE
Nov 23 14:10:05 ams pluto[16661]: | next event EVENT_RETRANSMIT in 19
seconds for #1

The output of status:

/usr/sbin/ipsec whack --status

[root at ams ipsec.d]# /usr/sbin/ipsec whack --status
000 interface lo/lo ::1
000 interface lo/lo 127.0.0.1
000 interface lo/lo 127.0.0.1
000 interface eth0/eth0 192.168.1.13
000 interface eth0/eth0 192.168.1.13
000 %myid = (none)
000 debug parsing+control
000  
000 algorithm ESP encrypt: id=2, name=ESP_DES, ivlen=8, keysizemin=64,
keysizemax=64
000 algorithm ESP encrypt: id=3, name=ESP_3DES, ivlen=8, keysizemin=192,
keysizemax=192
000 algorithm ESP encrypt: id=7, name=ESP_BLOWFISH, ivlen=8,
keysizemin=40, keysizemax=448
000 algorithm ESP encrypt: id=11, name=ESP_NULL, ivlen=0, keysizemin=0,
keysizemax=0
000 algorithm ESP encrypt: id=12, name=ESP_AES, ivlen=8, keysizemin=128,
keysizemax=256
000 algorithm ESP encrypt: id=252, name=ESP_SERPENT, ivlen=8,
keysizemin=128, keysizemax=256
000 algorithm ESP encrypt: id=253, name=ESP_TWOFISH, ivlen=8,
keysizemin=128, keysizemax=256
000 algorithm ESP auth attr: id=1, name=AUTH_ALGORITHM_HMAC_MD5,
keysizemin=128, keysizemax=128
000 algorithm ESP auth attr: id=2, name=AUTH_ALGORITHM_HMAC_SHA1,
keysizemin=160, keysizemax=160
000 algorithm ESP auth attr: id=5, name=AUTH_ALGORITHM_HMAC_SHA2_256,
keysizemin=256, keysizemax=256
000 algorithm ESP auth attr: id=251, name=(null), keysizemin=0,
keysizemax=0
000  
000 algorithm IKE encrypt: id=5, name=OAKLEY_3DES_CBC, blocksize=8,
keydeflen=192
000 algorithm IKE encrypt: id=7, name=OAKLEY_AES_CBC, blocksize=16,
keydeflen=128
000 algorithm IKE hash: id=1, name=OAKLEY_MD5, hashsize=16
000 algorithm IKE hash: id=2, name=OAKLEY_SHA1, hashsize=20
000 algorithm IKE dh group: id=2, name=OAKLEY_GROUP_MODP1024, bits=1024
000 algorithm IKE dh group: id=5, name=OAKLEY_GROUP_MODP1536, bits=1536
000 algorithm IKE dh group: id=14, name=OAKLEY_GROUP_MODP2048, bits=2048
000 algorithm IKE dh group: id=15, name=OAKLEY_GROUP_MODP3072, bits=3072
000 algorithm IKE dh group: id=16, name=OAKLEY_GROUP_MODP4096, bits=4096
000 algorithm IKE dh group: id=17, name=OAKLEY_GROUP_MODP6144, bits=6144
000 algorithm IKE dh group: id=18, name=OAKLEY_GROUP_MODP8192, bits=8192
000  
000 stats db_ops.c: {curr_cnt, total_cnt, maxsz} :context={0,1,64}
trans={0,1,672} attrs={0,1,224} 
000  
000 "sonicwall":
192.168.1.13/32===192.168.1.13...66.nnn.nnn.nnn===192.168.128.0/24;
unrouted; eroute owner: #0
000 "sonicwall":     srcip=unset; dstip=unset; srcup=ipsec _updown;
dstup=ipsec _updown;
000 "sonicwall":   ike_life: 3600s; ipsec_life: 28800s; rekey_margin:
540s; rekey_fuzz: 100%; keyingtries: 1
000 "sonicwall":   policy: PSK+ENCRYPT+TUNNEL+PFS+UP; prio: 32,24;
interface: eth0; 
000 "sonicwall":   newest ISAKMP SA: #0; newest IPsec SA: #0; 
000 "sonicwall":   IKE algorithms wanted: 5_000-1-5, 5_000-1-2,
flags=strict
000 "sonicwall":   IKE algorithms found:  5_192-1_128-5, 5_192-1_128-2, 
000 "sonicwall":   ESP algorithms wanted: 3_000-1, flags=strict
000 "sonicwall":   ESP algorithms loaded: 3_000-1, flags=strict
000  
000  
[root at ams ipsec.d]# 


Would appreciate if anybody can give me any pointers on how to
proceed/further debug. Yes, I have posted a similar situation before to
this list, but at that time the VPN server was configured for the old
DES rather than 3DES and most of the responses were to change this to
3DES and try again. Well, I did and still no success :(

Thanks in advance for your response.

Bas.











-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.openswan.org/pipermail/users/attachments/20061123/c0909100/attachment-0001.html

More information about the Users mailing list