[Openswan Users] Openswan cannot make connection with DrayTek in Aggressive Mode (packet rejected: should have been encrypted)

Nick Howitt n1ck.h0w1tt at gmail.com
Mon Sep 12 14:21:14 EDT 2011


*** This is a repost as Openswan/Xelerance blocked my ISP's smtp server 
over the w/e ***

Steve,

I use the older Vigor 2900 with a slightly different set up in that both 
the DrayTek and Openswan devices are gateway devices so there is not NAT 
but the DrayTek is on a dynamic IP so here are a few things from my set up:

I use main mode with PFS rather than aggressive mode as it is more secure.
Openswan responds correctly if you do not specify ike and phase2alg so 
try leaving them out if you switch to main mode. If you use aggressive 
mode, don't you need to fully specify phase2alg?
I use a rightid like you, but should not strings be preceded by an @?
I do not use a leftid but you may need to because you have a NAT device. 
You may need to set the leftid to the WAN IP of the Openswan device.
auto should be "add" as right = %any. Openswan cannot initiate to a 
dynamic IP.
I think rekey should be no as only the initiating end should start rekeying.

Have you tried looking at the DrayTek logs (either with DrayTek's own 
tool or Wallwatcher)?

Regards,

Nick

On 10/09/2011 11:34, Steve Leung wrote:
> Hi Paul,
>
>
>> So try initiating it from the draytek as well as initiating from openswan.
> Since the IP of the DrayTek always change, so the IPsec connection
> must be initiated by it and Openswan accepting right=%any and use
> rightid=ipsec at draytek to identify it using Aggressive Mode. Do you
> know is there any work around to ignore that "informational message"
> and make it works?
>
> My target:
>
> [DrayTek with dynamic IP]<==[ IPsec Tunnel (PSK, Aggressive) ]==>
> [OpenSWAN with static IP]
>
>
>
>> Also note that draytek will keep its phase1 ISAKMP up even after you
>> reconfigure it, so to be sure your config has taken hold, always reboot
>> these things.
> Thanks, I have tried to use Main Mode for testing purpose and I
> experienced this too... (but the tunnel is still working well) , now I
> know that it's DrayTek's problem but not mine :)
>
>
>
>> I would use:
>>         rightsubnet=192.168.1.1/24
>> same for leftsubnet, as it prevents instantiations of the conn that are not required
>> here
> Oh sorry for that, because there were more than one subnet and I just
> removed some of them and want to simplify the generated logs for
> debug.
>
>
>
>> Are you sure the draytek i using DH2? If it uses DH5 that is modp1536
>> double check if it has perfect forward secrecry disabled...
> Yes, I am sure it's using DH2 and PFS disabled.
>
>
>
>> You might want to check this with plutodebug=all.
> Here are the log messages with plutodebug=all, but I'm not familiar
> with these raw packets, could you give me a hand?
>
> ===
> Sep 10 17:20:45 openswan openswan: "IPSEC1/1x1"[1] 10.0.0.1 #50:
> transition from state STATE_AGGR_R0 to state STATE_AGGR_R1
> Sep 10 17:20:45 openswan openswan: | deleting event for #50
> Sep 10 17:20:45 openswan openswan: | sending reply packet to
> 10.0.0.1:500 (from port 500)
> Sep 10 17:20:45 openswan openswan: | sending 360 bytes for
> STATE_AGGR_R0 through eth2:500 to 10.0.0.1:500 (using #50)
> Sep 10 17:20:45 openswan openswan: |   8d a7 35 7c  a0 b3 3d 82  fb 85
> 2a 76  72 1d 3b ef
> Sep 10 17:20:45 openswan openswan: |   01 10 04 00  00 00 00 00  00 00
> 01 68  04 00 00 34
> Sep 10 17:20:45 openswan openswan: |   00 00 00 01  00 00 00 01  00 00
> 00 28  00 01 00 01
> Sep 10 17:20:45 openswan openswan: |   00 00 00 20  02 01 00 00  80 0b
> 00 01  80 0c 70 80
> Sep 10 17:20:45 openswan openswan: |   80 01 00 05  80 02 00 01  80 03
> 00 01  80 04 00 02
> Sep 10 17:20:45 openswan openswan: |   0a 00 00 84  6b 25 69 84  09 d2
> 87 60  40 13 88 c6
> Sep 10 17:20:45 openswan openswan: |   4e 6f 95 03  09 d7 eb 69  f7 b6
> 0c 3f  f7 7e 62 9a
> Sep 10 17:20:45 openswan openswan: |   f3 57 49 11  14 81 88 e6  f2 a8
> df a4  76 2a 31 5a
> Sep 10 17:20:45 openswan openswan: |   93 6e 56 9a  da eb fe 99  4a 98
> 75 2a  6a be 16 c8
> Sep 10 17:20:45 openswan openswan: |   50 f2 00 b2  dc bb ce 30  41 65
> 70 65  32 c2 2e d4
> Sep 10 17:20:45 openswan openswan: |   03 46 58 4a  3c fd 28 7d  11 ec
> 0a f4  e4 ab 97 76
> Sep 10 17:20:45 openswan openswan: |   04 43 27 35  41 2e ee cf  74 5d
> bf c0  ab 14 be 04
> Sep 10 17:20:45 openswan openswan: |   1b 38 e3 34  8d 22 ce f1  5d c6
> 7f 00  82 d9 23 03
> Sep 10 17:20:45 openswan openswan: |   28 f2 06 b4  05 00 00 14  8b af
> b9 56  45 06 d5 35
> Sep 10 17:20:45 openswan openswan: |   28 c7 96 e1  fc 94 4c a0  08 00
> 00 19  03 00 00 00
> Sep 10 17:20:45 openswan openswan: |   69 70 73 65  63 40 70 65  70 6c
> 69 6e  6b 2e 63 6f
> Sep 10 17:20:45 openswan openswan: |   6d 0d 00 00  14 14 54 56  16 70
> de 56  b9 bf 20 07
> Sep 10 17:20:45 openswan openswan: |   5d 88 95 e7  28 14 00 00  14 af
> ca d7  13 68 a1 f1
> Sep 10 17:20:45 openswan openswan: |   c9 6b 86 96  fc 77 57 01  00 14
> 00 00  14 27 5b b5
> Sep 10 17:20:45 openswan openswan: |   e5 ba 5b 44  2b c6 a1 ad  6f fb
> 36 9e  2a 0d 00 00
> Sep 10 17:20:45 openswan openswan: |   14 8c 29 7f  75 1f d8 39  65 7a
> 95 c9  7f 13 04 31
> Sep 10 17:20:45 openswan openswan: |   05 00 00 00  14 4a 13 1c  81 07
> 03 58  45 5c 57 28
> Sep 10 17:20:45 openswan openswan: |   f2 0e 95 45  2f 00 00 00
> Sep 10 17:20:45 openswan openswan: | inserting event EVENT_RETRANSMIT,
> timeout in 10 seconds for #50
> Sep 10 17:20:45 openswan openswan: | event added after event
> EVENT_RETRANSMIT for #46
> Sep 10 17:20:45 openswan openswan: "IPSEC1/1x1"[1] 10.0.0.1 #50:
> STATE_AGGR_R1: sent AR1, expecting AI2
> Sep 10 17:20:45 openswan openswan: | modecfg pull: noquirk policy:push
> not-client
> Sep 10 17:20:45 openswan openswan: | phase 1 is done, looking for
> phase 2 to unpend
> Sep 10 17:20:45 openswan openswan: | complete state transition with STF_INLINE
> Sep 10 17:20:45 openswan openswan: | complete state transition with STF_INLINE
> Sep 10 17:20:45 openswan openswan: | * processed 0 messages from
> cryptographic helpers
> Sep 10 17:20:45 openswan openswan: | next event EVENT_RETRANSMIT in 5
> seconds for #46
> Sep 10 17:20:45 openswan openswan: | next event EVENT_RETRANSMIT in 5
> seconds for #46
> Sep 10 17:20:46 openswan openswan: |
> Sep 10 17:20:46 openswan openswan: | *received 88 bytes from
> 10.0.0.1:500 on eth2 (port=500)
> Sep 10 17:20:46 openswan openswan: |   8d a7 35 7c  a0 b3 3d 82  fb 85
> 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: |   08 10 04 00  00 00 00 00  00 00
> 00 58  14 00 00 14
> Sep 10 17:20:46 openswan openswan: |   8f ce 27 3c  7a 00 1b 11  38 7b
> 7e d9  b3 ae 58 57
> Sep 10 17:20:46 openswan openswan: |   14 00 00 14  8c 29 7f 75  1f d8
> 39 65  7a 95 c9 7f
> Sep 10 17:20:46 openswan openswan: |   13 04 31 05  00 00 00 14  27 5b
> b5 e5  ba 5b 44 2b
> Sep 10 17:20:46 openswan openswan: |   c6 a1 ad 6f  fb 36 9e 2a
> Sep 10 17:20:46 openswan openswan: | **parse ISAKMP Message:
> Sep 10 17:20:46 openswan openswan: |    initiator cookie:
> Sep 10 17:20:46 openswan openswan: |   8d a7 35 7c  a0 b3 3d 82
> Sep 10 17:20:46 openswan openswan: |    responder cookie:
> Sep 10 17:20:46 openswan openswan: |   fb 85 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: |    next payload type: ISAKMP_NEXT_HASH
> Sep 10 17:20:46 openswan openswan: |    ISAKMP version: ISAKMP Version
> 1.0 (rfc2407)
> Sep 10 17:20:46 openswan openswan: |    exchange type: ISAKMP_XCHG_AGGR
> Sep 10 17:20:46 openswan openswan: |    flags: none
> Sep 10 17:20:46 openswan openswan: |    message ID:  00 00 00 00
> Sep 10 17:20:46 openswan openswan: |    length: 88
> Sep 10 17:20:46 openswan openswan: |  processing version=1.0 packet
> with exchange type=ISAKMP_XCHG_AGGR (4)
> Sep 10 17:20:46 openswan openswan: | ICOOKIE:  8d a7 35 7c  a0 b3 3d 82
> Sep 10 17:20:46 openswan openswan: | RCOOKIE:  fb 85 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: | state hash entry 6
> Sep 10 17:20:46 openswan openswan: | v1 peer and cookies match on #50,
> provided msgid 00000000 vs 00000000
> Sep 10 17:20:46 openswan openswan: | v1 state object #50 found, in STATE_AGGR_R1
> Sep 10 17:20:46 openswan openswan: | processing connection
> IPSEC1/1x1[1] 10.0.0.1
> Sep 10 17:20:46 openswan openswan: "IPSEC1/1x1"[1] 10.0.0.1 #50:
> packet rejected: should have been encrypted
> Sep 10 17:20:46 openswan openswan: "IPSEC1/1x1"[1] 10.0.0.1 #50:
> sending notification INVALID_FLAGS to 10.0.0.1:500
> Sep 10 17:20:46 openswan openswan: | **emit ISAKMP Message:
> Sep 10 17:20:46 openswan openswan: |    initiator cookie:
> Sep 10 17:20:46 openswan openswan: |   8d a7 35 7c  a0 b3 3d 82
> Sep 10 17:20:46 openswan openswan: |    responder cookie:
> Sep 10 17:20:46 openswan openswan: |   fb 85 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: |    next payload type: ISAKMP_NEXT_N
> Sep 10 17:20:46 openswan openswan: |    ISAKMP version: ISAKMP Version
> 1.0 (rfc2407)
> Sep 10 17:20:46 openswan openswan: |    exchange type: ISAKMP_XCHG_INFO
> Sep 10 17:20:46 openswan openswan: |    flags: none
> Sep 10 17:20:46 openswan openswan: |    message ID:  48 61 b2 32
> Sep 10 17:20:46 openswan openswan: | ***emit ISAKMP Notification Payload:
> Sep 10 17:20:46 openswan openswan: |    next payload type: ISAKMP_NEXT_NONE
> Sep 10 17:20:46 openswan openswan: |    DOI: ISAKMP_DOI_IPSEC
> Sep 10 17:20:46 openswan openswan: |    protocol ID: 1
> Sep 10 17:20:46 openswan openswan: |    SPI size: 0
> Sep 10 17:20:46 openswan openswan: |    Notify Message Type: INVALID_FLAGS
> Sep 10 17:20:46 openswan openswan: | emitting length of ISAKMP
> Notification Payload: 12
> Sep 10 17:20:46 openswan openswan: | emitting length of ISAKMP Message: 40
> Sep 10 17:20:46 openswan openswan: | sending 40 bytes for notification
> packet through eth2:500 to 10.0.0.1:500 (using #50)
> Sep 10 17:20:46 openswan openswan: |   8d a7 35 7c  a0 b3 3d 82  fb 85
> 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: |   0b 10 05 00  48 61 b2 32  00 00
> 00 28  00 00 00 0c
> Sep 10 17:20:46 openswan openswan: |   00 00 00 01  01 00 00 08
> Sep 10 17:20:46 openswan openswan: | * processed 0 messages from
> cryptographic helpers
> Sep 10 17:20:46 openswan openswan: | next event EVENT_RETRANSMIT in 4
> seconds for #46
> Sep 10 17:20:46 openswan openswan: | next event EVENT_RETRANSMIT in 4
> seconds for #46
> Sep 10 17:20:46 openswan openswan: |
> Sep 10 17:20:46 openswan openswan: | *received 148 bytes from
> 10.0.0.1:500 on eth2 (port=500)
> Sep 10 17:20:46 openswan openswan: |   8d a7 35 7c  a0 b3 3d 82  fb 85
> 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: |   08 10 20 01  ec f3 f7 fa  00 00
> 00 94  f1 c7 98 f0
> Sep 10 17:20:46 openswan openswan: |   c1 d3 fa 43  ae ae c2 bb  77 84
> f8 6c  02 4c ed a6
> Sep 10 17:20:46 openswan openswan: |   31 3b 6b 6c  66 ff 13 0d  39 cc
> 07 9a  f0 f4 5a eb
> Sep 10 17:20:46 openswan openswan: |   b8 d8 2c 58  f7 12 87 4f  3b 2d
> 1a da  34 f4 10 21
> Sep 10 17:20:46 openswan openswan: |   a4 0b 8a 4c  63 8b 15 6e  79 ad
> ba 24  a2 86 b3 4a
> Sep 10 17:20:46 openswan openswan: |   70 fc 7e 42  f4 98 f4 0b  ea 67
> 04 3a  ad 13 08 ae
> Sep 10 17:20:46 openswan openswan: |   32 ee 87 c1  cc fa 71 f1  87 d0
> 71 ec  65 6d 75 69
> Sep 10 17:20:46 openswan openswan: |   c6 24 13 c1  50 c0 29 32  fb 20
> cb bb  ab 61 59 a9
> Sep 10 17:20:46 openswan openswan: |   1e 47 b1 b5
> Sep 10 17:20:46 openswan openswan: | **parse ISAKMP Message:
> Sep 10 17:20:46 openswan openswan: |    initiator cookie:
> Sep 10 17:20:46 openswan openswan: |   8d a7 35 7c  a0 b3 3d 82
> Sep 10 17:20:46 openswan openswan: |    responder cookie:
> Sep 10 17:20:46 openswan openswan: |   fb 85 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: |    next payload type: ISAKMP_NEXT_HASH
> Sep 10 17:20:46 openswan openswan: |    ISAKMP version: ISAKMP Version
> 1.0 (rfc2407)
> Sep 10 17:20:46 openswan openswan: |    exchange type: ISAKMP_XCHG_QUICK
> Sep 10 17:20:46 openswan openswan: |    flags: ISAKMP_FLAG_ENCRYPTION
> Sep 10 17:20:46 openswan openswan: |    message ID:  ec f3 f7 fa
> Sep 10 17:20:46 openswan openswan: |    length: 148
> Sep 10 17:20:46 openswan openswan: |  processing version=1.0 packet
> with exchange type=ISAKMP_XCHG_QUICK (32)
> Sep 10 17:20:46 openswan openswan: | ICOOKIE:  8d a7 35 7c  a0 b3 3d 82
> Sep 10 17:20:46 openswan openswan: | RCOOKIE:  fb 85 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: | state hash entry 6
> Sep 10 17:20:46 openswan openswan: | v1 peer and cookies match on #50,
> provided msgid ecf3f7fa vs 00000000
> Sep 10 17:20:46 openswan openswan: | v1 state object not found
> Sep 10 17:20:46 openswan openswan: | ICOOKIE:  8d a7 35 7c  a0 b3 3d 82
> Sep 10 17:20:46 openswan openswan: | RCOOKIE:  fb 85 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: | state hash entry 6
> Sep 10 17:20:46 openswan openswan: | v1 peer and cookies match on #50,
> provided msgid 00000000 vs 00000000
> Sep 10 17:20:46 openswan openswan: | v1 state object #50 found, in STATE_AGGR_R1
> Sep 10 17:20:46 openswan openswan: | processing connection
> IPSEC1/1x1[1] 10.0.0.1
> Sep 10 17:20:46 openswan openswan: "IPSEC1/1x1"[1] 10.0.0.1 #50: Quick
> Mode message is unacceptable because it is for an incomplete ISAKMP SA
> Sep 10 17:20:46 openswan openswan: | payload malformed after IV
> Sep 10 17:20:46 openswan openswan: |   8a 6f 23 39  7b ad 3e dd  17 a4
> e8 97  2a d0 c1 d8
> Sep 10 17:20:46 openswan openswan: "IPSEC1/1x1"[1] 10.0.0.1 #50:
> sending notification PAYLOAD_MALFORMED to 10.0.0.1:500
> Sep 10 17:20:46 openswan openswan: | **emit ISAKMP Message:
> Sep 10 17:20:46 openswan openswan: |    initiator cookie:
> Sep 10 17:20:46 openswan openswan: |   8d a7 35 7c  a0 b3 3d 82
> Sep 10 17:20:46 openswan openswan: |    responder cookie:
> Sep 10 17:20:46 openswan openswan: |   fb 85 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: |    next payload type: ISAKMP_NEXT_N
> Sep 10 17:20:46 openswan openswan: |    ISAKMP version: ISAKMP Version
> 1.0 (rfc2407)
> Sep 10 17:20:46 openswan openswan: |    exchange type: ISAKMP_XCHG_INFO
> Sep 10 17:20:46 openswan openswan: |    flags: none
> Sep 10 17:20:46 openswan openswan: |    message ID:  65 54 88 71
> Sep 10 17:20:46 openswan openswan: | ***emit ISAKMP Notification Payload:
> Sep 10 17:20:46 openswan openswan: |    next payload type: ISAKMP_NEXT_NONE
> Sep 10 17:20:46 openswan openswan: |    DOI: ISAKMP_DOI_IPSEC
> Sep 10 17:20:46 openswan openswan: |    protocol ID: 1
> Sep 10 17:20:46 openswan openswan: |    SPI size: 0
> Sep 10 17:20:46 openswan openswan: |    Notify Message Type: PAYLOAD_MALFORMED
> Sep 10 17:20:46 openswan openswan: | emitting length of ISAKMP
> Notification Payload: 12
> Sep 10 17:20:46 openswan openswan: | emitting length of ISAKMP Message: 40
> Sep 10 17:20:46 openswan openswan: | sending 40 bytes for notification
> packet through eth2:500 to 10.0.0.1:500 (using #50)
> Sep 10 17:20:46 openswan openswan: |   8d a7 35 7c  a0 b3 3d 82  fb 85
> 2a 76  72 1d 3b ef
> Sep 10 17:20:46 openswan openswan: |   0b 10 05 00  65 54 88 71  00 00
> 00 28  00 00 00 0c
> Sep 10 17:20:46 openswan openswan: |   00 00 00 01  01 00 00 10
> Sep 10 17:20:46 openswan openswan: | * processed 0 messages from
> cryptographic helpers
> Sep 10 17:20:46 openswan openswan: | next event EVENT_RETRANSMIT in 4
> seconds for #46
> Sep 10 17:20:46 openswan openswan: | next event EVENT_RETRANSMIT in 4
> seconds for #46
> ===
>
>
> Thank you very much for your help, I have learnt so much from your
> Openswan book :)
>
>
>
> Best regards,
> Steve
> _______________________________________________
> Users at openswan.org
> http://lists.openswan.org/mailman/listinfo/users
> Micropayments: https://flattr.com/thing/38387/IPsec-for-Linux-made-easy
> Building and Integrating Virtual Private Networks with Openswan:
> http://www.amazon.com/gp/product/1904811256/104-3099591-2946327?n=283155


More information about the Users mailing list