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

Steve Leung kesteve at kesteve.com
Sat Sep 10 06:34:59 EDT 2011 

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

More information about the Users mailing list