[Openswan Users] !pluto failure!: exited with error status 128
Zhiping Liu
flyingzpl at gmail.com
Thu Jun 25 05:31:18 EDT 2009
Hi Paul: Sorry,i forgot to turn on "DEBUG",here's the debug message:
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"""aa""[1] 113.89.243.199
#5: sending notification INVALID_ID_INFORMATION to 113.89.243.199:500"
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"""aa""[1] 113.89.243.199
#5: initial Aggressive Mode packet claiming to be from @test26 on
113.89.243.199 but no connection has been authorized"
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"""aa""[1] 113.89.243.199
#5: no suitable connection for peer '@test901'"
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"""aa""[1] 113.89.243.199
#5: Aggressive mode peer ID is ID_FQDN: '@test901'"
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"packet from
113.89.243.199:500: received Vendor ID payload
[draft-ietf-ipsec-nat-t-ike-00]"
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"packet from
113.89.243.199:500: received Vendor ID payload
[draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 109"
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"packet from
113.89.243.199:500: received Vendor ID payload
[draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but already using method 109"
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"packet from
113.89.243.199:500: received Vendor ID payload
[draft-ietf-ipsec-nat-t-ike-03] meth=108, but already using method 109"
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"packet from
113.89.243.199:500: received Vendor ID payload [RFC 3947] method set to=109
"
17:22:35,,secur/auth,Warning,pluto[11507],SSLVPN,"packet from
113.89.243.199:500: received Vendor ID payload [Dead Peer Detection]"
17:22:35,,system,Error,ipsec__plutorun,SSLVPN,"restarting IPsec after
pause..."
17:22:35,,system,Error,ipsec__plutorun,SSLVPN,"!pluto failure!: exited with
error status 128"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| next payload type:
ISAKMP_NEXT_VID"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| ***parse ISAKMP
Identification Payload:"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| got payload
0x20(ISAKMP_NEXT_ID) needed: 0x20 opt: 0x102000"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| length: 20"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| next payload type:
ISAKMP_NEXT_ID"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| ***parse ISAKMP Nonce
Payload:"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| got payload
0x400(ISAKMP_NEXT_NONCE) needed: 0x420 opt: 0x102000"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| length: 132"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| next payload type:
ISAKMP_NEXT_NONCE"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| ***parse ISAKMP Key
Exchange Payload:"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| got payload
0x10(ISAKMP_NEXT_KE) needed: 0x430 opt: 0x102000"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| DOI: ISAKMP_DOI_IPSEC"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| length: 52"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| next payload type:
ISAKMP_NEXT_KE"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| ***parse ISAKMP Security
Association Payload:"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| got payload
0x2(ISAKMP_NEXT_SA) needed: 0x432 opt: 0x102000"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| processing version=1.0
packet with exchange type=ISAKMP_XCHG_AGGR (4)"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| length: 368"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| message ID: 00 00 00
00"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| flags: none"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| exchange type:
ISAKMP_XCHG_AGGR"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| ISAKMP version: ISAKMP
Version 1.0 (rfc2407)"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| next payload type:
ISAKMP_NEXT_SA"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 00 00 00 00 00 00 00
00"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| responder cookie:"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 95 82 b8 33 4a ad 13
18"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| initiator cookie:"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| **parse ISAKMP Message:"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 44 85 15 2d 18 b6 bb cd
0b e8 a8 46 95 79 dd cc"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 35 df 21 f8 7c fd b2 fc
68 b6 a4 48 00 00 00 14"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 08 63 81 b5 ec 42 7b 1f
0d 00 00 14 cd 60 46 43"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 15 52 9d 56 0d 00 00 14
90 cb 80 91 3e bb 69 6e"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 0d 00 00 14 7d 94 19 a6
53 10 ca 6f 2c 17 9d 92"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 4a 13 1c 81 07 03 58 45
5c 57 28 f2 0e 95 45 2f"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 68 a1 f1 c9 6b 86 96 fc
77 57 01 00 0d 00 00 14"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 63 79 6c 61 6e 39 30 31
0d 00 00 14 af ca d7 13"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 74 23 de 13 c0 6e c8 2a
0d 00 00 10 02 00 00 00"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 04 32 02 c0 05 00 00 14
b8 69 3a 09 2d db 56 91"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 57 4d 8f 78 6a 11 89 ee
16 61 6d 73 58 3b e0 3b"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 14 8d 68 11 f6 ec 2f d0
7a 9a 01 72 75 ae 0a 04"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| c6 80 a7 a9 44 ad 4e f8
81 2a 21 06 dd a4 4a 99"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 8d d7 97 0d f9 c8 2b 61
6d 83 f2 90 d3 01 4d f6"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| e8 b4 c7 39 1f 70 68 73
f4 14 c4 4b d1 34 ba 94"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| e5 97 ad 8b f2 41 72 ee
dc a6 70 da 8f ba aa 5f"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 83 d2 9b 67 b9 5d e5 f8
b7 8b a8 a8 56 d7 ad c8"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 0a 00 00 84 87 a7 a9 07
58 31 13 48 31 c1 58 50"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 80 01 00 05 80 02 00 02
80 03 00 01 80 04 00 02"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 00 00 00 20 00 01 00 00
80 0b 00 01 80 0c 0e 10"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 00 00 00 01 00 00 00 01
00 00 00 28 00 01 00 01"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 01 10 04 00 00 00 00 00
00 00 01 70 04 00 00 34"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| 95 82 b8 33 4a ad 13 18
00 00 00 00 00 00 00 00"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| *received 368 bytes from
113.89.243.199:500 on ppp0 (port=500)"
17:22:34,,secur/auth,Debug,pluto[11507],SSLVPN,"| "
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.810000] klips_debug: IP:
ihl:20 ver:4 tos:0 tlen:136 id:19872 frag_off:0 ttl:64 proto:50 (ESP)
chk:49481 saddr:113.88.151.45 daddr:113.89.241.123"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.800000]
klips_debug:ipsec_xmit_send: ...done, calling ip_send() on device:ppp0"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.790000]
klips_debug:ipsec_xmit_restore_hard_header: With hard_header, final
head,tailroom: 64,24"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.780000]
klips_debug:ipsec_xmit_restore_hard_header: After recursive xforms --
head,tailroom: 64,24"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.780000] klips_debug:rj_match:
***** not found."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.770000] klips_debug:rj_match:
***** cp2=0pca5821d8 cp3=0pcbbe551c"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.760000] klips_debug:rj_match:
**** t=0pcbbbabac"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.760000] klips_debug:rj_match:
**** t=0pca4d1864"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.750000] klips_debug:rj_match:
*** start searching up the tree, t=0pca4d184c"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.750000] klips_debug:rj_match: **
try to match a leaf, t=0pca4d184c"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.740000] klips_debug:rj_match: *
See if we match exactly as a host destination"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.730000]
klips_debug:ipsec_findroute: 113.88.151.45:0->113.89.241.123:0 50"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.720000] ipsec_sa_put: ipsec_sa
ca488c84 SA:esp.c2f425f1 at 113.89.241.123 <SA%3Aesp.c2f425f1 at 113.89.241.123>,
ref:18 reference count (4--) decremented by ipsec_xmit_cont:1096."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.700000] klips_debug: IP:
ihl:20 ver:4 tos:0 tlen:136 id:19872 frag_off:0 ttl:64 proto:50 (ESP)
chk:49481 saddr:113.88.151.45 daddr:113.89.241.123"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.690000]
klips_debug:ipsec_xmit_encap_once: after <ESP_3DES_HMAC_SHA1>,
SA:esp.c2f425f1 at 113.89.241.123 <SA%3Aesp.c2f425f1 at 113.89.241.123>:"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.690000]
klips_debug:ipsec_alg_esp_encrypt: returned ret=1"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.680000]
klips_debug:ipsec_alg_esp_encrypt: calling cbc_encrypt encalg=3
ips_key_e=cbba55b8 idat=ca5936a0 ilen=88 iv=ca593698, encrypt=1"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.670000]
klips_debug:ipsec_alg_esp_encrypt: entering with encalg=3, ixt_e=bf1924e4"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.660000]
klips_debug:ipsec_xmit_encap_once: head,tailroom: 64,24 before xform."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.650000]
klips_debug:ipsec_xmit_encap_once: pushing 16 bytes, putting 16, proto 50."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.640000]
klips_debug:ipsec_xmit_encap_once: calling output for <ESP_3DES_HMAC_SHA1>,
SA:esp.c2f425f1 at 113.89.241.123 <SA%3Aesp.c2f425f1 at 113.89.241.123>"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.630000] ipsec_sa_get: ipsec_sa
ca488c84 SA:esp.c2f425f1 at 113.89.241.123 <SA%3Aesp.c2f425f1 at 113.89.241.123>,
ref:18 reference count (3++) incremented by ipsec_xmit_cont:1101."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.620000] ipsec_sa_put: ipsec_sa
ca4890b0 SA:tun.1001 at 113.89.241.123 <SA%3Atun.1001 at 113.89.241.123>, ref:17
reference count (3--) decremented by ipsec_xmit_cont:1096."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.600000] klips_debug: IP:
ihl:20 ver:4 tos:0 tlen:104 id:19872 frag_off:0 ttl:64 proto:4 chk:49559
saddr:113.88.151.45 daddr:113.89.241.123"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.600000]
klips_debug:ipsec_xmit_encap_once: after <IPIP>,
SA:tun.1001 at 113.89.241.123<SA%3Atun.1001 at 113.89.241.123>
:"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.590000]
klips_debug:ipsec_xmit_encap_once: head,tailroom: 80,40 before xform."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.580000]
klips_debug:ipsec_xmit_encap_once: pushing 20 bytes, putting 0, proto 4."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.570000]
klips_debug:ipsec_xmit_encap_once: calling output for <IPIP>,
SA:tun.1001 at 113.89.241.123 <SA%3Atun.1001 at 113.89.241.123>"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.560000] klips_debug: IP:
ihl:20 ver:4 tos:0 tlen:84 id:0 DF frag_off:0 ttl:64 proto:1 (ICMP)
chk:59477 saddr:192.168.100.1 daddr:192.168.109.1 type:code=8:0"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.550000]
klips_debug:ipsec_xmit_init2: head,tailroom: 100,40 after allocation"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.540000]
klips_debug:ipsec_xmit_init2: hard header already stripped."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.530000]
klips_info:ipsec_xmit_init2: dev ipsec0 mtu of 1454 decreased by 57 to 1397"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.520000]
klips_debug:ipsec_xmit_init2: mtu:1454 physmtu:1454 tothr:36 tottr:16
mtudiff:52 ippkttotlen:84"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.510000]
klips_debug:ipsec_xmit_init2: existing head,tailroom: 32,44 before applying
xforms with head,tailroom: 36,16 ."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.510000]
klips_debug:ipsec_xmit_init2: Required head,tailroom: 16,16"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.500000]
klips_debug:ipsec_xmit_init2: calling room for <ESP_3DES_HMAC_SHA1>,
SA:esp.c2f425f1 at 113.89.241.123 <SA%3Aesp.c2f425f1 at 113.89.241.123>"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.490000]
klips_debug:ipsec_xmit_init2: Required head,tailroom: 20,0"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.480000]
klips_debug:ipsec_xmit_init2: calling room for <IPIP>,
SA:tun.1001 at 113.89.241.123 <SA%3Atun.1001 at 113.89.241.123>"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.470000]
klips_debug:ipsec_xmit_init2: found ipsec_sa -- SA:<IPIP>
tun.1001 at 113.89.241.123"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.460000] ipsec_sa_get: ipsec_sa
ca4890b0 SA:tun.1001 at 113.89.241.123 <SA%3Atun.1001 at 113.89.241.123>, ref:17
reference count (2++) incremented by ipsec_sa_getbyid:552."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.450000] ipsec_sa_getbyid: linked
entry in ipsec_sa table for hash=104 of
SA:tun.1001 at 113.89.241.123<SA%3Atun.1001 at 113.89.241.123>requested."
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.440000]
klips_debug:ipsec_xmit_SAlookup: checking for local udp/500 IKE packet
saddr=c0a86401, er=0pca4d184c, daddr=c0a86d01, er_dst=7159f17b, proto=1
sport=0 dport=0"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.440000] klips_debug:rj_match: **
try to match a leaf, t=0pca4d184c"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.430000] klips_debug:rj_match: *
See if we match exactly as a host destination"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.420000]
klips_debug:ipsec_findroute: 192.168.100.1:0->192.168.109.1:0 1"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.410000]
klips_debug:ipsec_xmit_strip_hard_header: Original head,tailroom: 32,44"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.400000] klips_debug: IP:
ihl:20 ver:4 tos:0 tlen:84 id:0 DF frag_off:0 ttl:64 proto:1 (ICMP)
chk:59477 saddr:192.168.100.1 daddr:192.168.109.1 type:code=8:0"
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.380000] ipsec_tunnel_start_xmit:
STARTING<6>klips_debug:ipsec_xmit_strip_hard_header: >>> skb->len=84
hard_header_len:22
45:00:00:54:00:00:40:00:40:01:e8:55:c0:a8:64:01:c0:a8:6d:01:08:00 "
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.380000] "
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.380000] "
17:22:33,,kernel,Info,kernel,SSLVPN,"[83913.370000]
klips_debug:ipsec_tunnel_neigh_setup:"
2009/6/25 Zhiping Liu <flyingzpl at gmail.com>
> Hi Paul:
> Here's the log on the WAN-WAN server side,but i can not find anything
> helpfull...
> I have no idea what to do now.
>
> Source IP,Generated,Received,Source
> Name,Facility,Severity,Tag,Origin,Message
> 17:09:37,,clock,Notice,crond[1714],SSLVPN,"USER root pid 10492 cmd
> /testshell/spy.sh"
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"""aa""[1] 113.89.243.199
> #1: sending notification INVALID_ID_INFORMATION to 113.89.243.199:500"
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"""aa""[1] 113.89.243.199
> #1: initial Aggressive Mode packet claiming to be from @test26 on
> 113.89.243.199 but no connection has been authorized"
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"""aa""[1] 113.89.243.199
> #1: no suitable connection for peer '@test901'"
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"""aa""[1] 113.89.243.199
> #1: Aggressive mode peer ID is ID_FQDN: '@test901'"
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-00]"
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 109"
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but already using method 109"
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-03] meth=108, but already using method 109"
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload [RFC 3947] method set
> to=109 "
> 17:08:44,,secur/auth,Warning,pluto[10411],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload [Dead Peer Detection]"
> 17:08:37,,clock,Notice,crond[1714],SSLVPN,"USER root pid 10431 cmd
> /testshell/spy.sh"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"loading secrets from
> ""/testconf/ipsec.secrets.d/101.secret"""
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"loaded private key for
> keyid: PPK_RSA:AQN82KZkW"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"loading secrets from
> ""/etc/ipsec.secrets"""
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"adding interface
> ipsec0/ppp0 113.88.151.45:4500"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"adding interface
> ipsec0/ppp0 113.88.151.45:500"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"IP interfaces ppp1 and
> eth1 share address 192.168.100.1!"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"IP interfaces ppp2 and
> eth1 share address 192.168.100.1!"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"IP interfaces ppp2 and
> ppp1 share address 192.168.100.1!"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"listening for IKE
> messages"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"added connection
> description ""aa"""
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"Warning: empty directory"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"Changing to directory
> '/etc/ipsec.d/crls'"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"Changed path to directory
> '/etc/ipsec.d/ocspcerts'"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"Changed path to directory
> '/etc/ipsec.d/aacerts'"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"Changed path to directory
> '/etc/ipsec.d/cacerts'"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"Using KLIPS IPsec
> interface code on 2.6.28.9"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"no helpers will be
> started, all cryptographic operations will be done inline"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"ike_alg_register_hash():
> Activating OAKLEY_SHA2_256: Ok (ret=0)"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"ike_alg_register_hash():
> Activating OAKLEY_SHA2_512: Ok (ret=0)"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"ike_alg_register_enc():
> Activating OAKLEY_BLOWFISH_CBC: Ok (ret=0)"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"ike_alg_register_enc():
> Activating OAKLEY_AES_CBC: Ok (ret=0)"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"ike_alg_register_enc():
> Activating OAKLEY_SERPENT_CBC: Ok (ret=0)"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"ike_alg_register_enc():
> Activating OAKLEY_TWOFISH_CBC: Ok (ret=0)"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"ike_alg_register_enc():
> Activating OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"using /dev/urandom as
> source of random entropy"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"including NAT-Traversal
> patch (Version 0.6c)"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"port floating activation
> criteria nat_t=1/port_float=1"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"Setting NAT-Traversal
> port-4500 floating to on"
> 17:08:09,,secur/auth,Warning,pluto[10411],SSLVPN,"Starting Pluto (Openswan
> Version 2.6.21; Vendor ID OE~q\177kZNr}Wk) pid:10411"
> 17:08:09,,user-level,Warning,pluto,SSLVPN,"adjusting ipsec.d to
> /etc/ipsec.d"
> 17:08:09,,system,Error,ipsec__plutorun,SSLVPN,"003 IP interfaces ppp1 and
> eth1 share address 192.168.100.1!"
> 17:08:09,,system,Error,ipsec__plutorun,SSLVPN,"003 IP interfaces ppp2 and
> eth1 share address 192.168.100.1!"
> 17:08:09,,system,Error,ipsec__plutorun,SSLVPN,"003 IP interfaces ppp2 and
> ppp1 share address 192.168.100.1!"
> 17:08:09,,system,Error,ipsec__plutorun,SSLVPN,"002 added connection
> description ""aa"""
> 17:08:09,,system,Error,ipsec_setup,SSLVPN,"...Openswan IPsec started"
> 17:08:09,,system,Error,ipsec__plutorun,SSLVPN,"adjusting ipsec.d to
> /etc/ipsec.d"
> 17:08:09,,secur/auth,Error,ipsec__plutorun,SSLVPN,"Restarting Pluto
> subsystem..."
> 17:08:08,,kernel,Warning,kernel,SSLVPN,"[83049.550000] "
> 17:08:08,,system,Error,ipsec_setup,SSLVPN,"KLIPS ipsec1 on eth1
> 192.168.100.1/255.255.255.0 broadcast 192.168.100.255 "
> 17:08:08,,system,Error,ipsec_setup,SSLVPN,"KLIPS ipsec0 on ppp0
> 113.88.151.45/255.255.255.255 pointopoint 113.88.150.1 "
> 17:08:08,,system,Error,ipsec_setup,SSLVPN,"KLIPS debug `none'"
> 17:08:07,,system,Error,ipsec_setup,SSLVPN,"Using KLIPS/legacy stack"
> 17:08:07,,system,Error,ipsec_setup,SSLVPN,"Restarting Openswan IPsec
> 2.6.21..."
> 17:08:07,,system,Error,ipsec_setup,SSLVPN,"...Openswan IPsec stopped"
> 17:08:06,,kernel,Warning,kernel,SSLVPN,"[83048.200000] "
> 17:08:06,,kernel,Critical,kernel,SSLVPN,"[83047.990000] IPSEC EVENT: KLIPS
> device ipsec1 shut down."
> 17:08:06,,kernel,Critical,kernel,SSLVPN,"[83047.820000] IPSEC EVENT: KLIPS
> device ipsec0 shut down."
> 17:08:05,,secur/auth,Warning,pluto[9357],SSLVPN,"shutting down interface
> ipsec0/ppp0 113.88.151.45:500"
> 17:08:05,,secur/auth,Warning,pluto[9357],SSLVPN,"shutting down interface
> ipsec0/ppp0 113.88.151.45:4500"
> 17:08:05,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa"": deleting
> connection"
> 17:08:05,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[1] 113.89.243.199:
> deleting connection ""aa"" instance with peer 113.89.243.199
> {isakmp=#0/ipsec=#0}"
> 17:08:05,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa"" #22: deleting state
> (STATE_AGGR_R2)"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa"" #23: deleting state
> (STATE_QUICK_R2)"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123:
> deleting connection ""aa"" instance with peer 113.89.241.123
> {isakmp=#22/ipsec=#23}"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"forgetting secrets"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"shutting down"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[1] 113.89.243.199
> #24: sending notification INVALID_ID_INFORMATION to 113.89.243.199:500"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[1] 113.89.243.199
> #24: initial Aggressive Mode packet claiming to be from @test26 on
> 113.89.243.199 but no connection has been authorized"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[1] 113.89.243.199
> #24: no suitable connection for peer '@test901'"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[1] 113.89.243.199
> #24: Aggressive mode peer ID is ID_FQDN: '@test901'"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-00]"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 109"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but already using method 109"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-03] meth=108, but already using method 109"
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload [RFC 3947] method set
> to=109 "
> 17:08:04,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload [Dead Peer Detection]"
> 17:08:04,,system,Error,ipsec_setup,SSLVPN,"Stopping Openswan IPsec..."
> 17:07:59,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #23: DPD Error: could not find newest phase 1 state"
> 17:07:55,,secur/auth,Warning,pluto[9357],SSLVPN,"reapchild failed with
> errno=10 No child processes"
> 17:07:55,,secur/auth,Warning,pluto[9357],SSLVPN,"ADNS process exited with
> status 1"
> 17:07:54,,system,Error,ipsec__plutorun,SSLVPN,"restarting IPsec after
> pause..."
> 17:07:54,,system,Error,ipsec__plutorun,SSLVPN,"!pluto failure!: exited
> with error status 128"
> 17:07:40,,local 2,Notice,sudo,SSLVPN,"www : TTY=pts/0 ;
> PWD=/testapp/config/apache/htdocs/language_zh_CN ; USER=root ;
> COMMAND=/sbin/ipsec whack --status"
> 17:07:37,,clock,Notice,crond[1714],SSLVPN,"USER root pid 10198 cmd
> /testshell/spy.sh"
> 17:07:30,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #23: STATE_QUICK_R2: IPsec SA established tunnel mode {ESP=>0x291ae3f6
> <0xcdf87c67 xfrm=3DES_0-HMAC_SHA1 NATOA=none NATD=none DPD=enabled}"
> 17:07:30,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #23: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2"
> 17:07:30,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #23: Dead Peer Detection (RFC 3706): enabled"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #23: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #23: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #23: them: 113.89.241.123<0.0.0.0>[@test26,+S=C]===192.168.109.0/24"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #23: us: 192.168.100.0/24===113.88.151.45[@testyf,+S=C]<http://192.168.100.0/24===113.88.151.45%5B@testyf,+S=C%5D>
> "
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #23: responding to Quick Mode proposal {msgid:26673bba}"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #22: the peer proposed: 192.168.100.0/24:0/0 -> 192.168.109.0/24:0/0"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #22: Dead Peer Detection (RFC 3706): enabled"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #22: STATE_AGGR_R2: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY
> cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1024}"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #22: transition from state STATE_AGGR_R1 to state STATE_AGGR_R2"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #22: NAT-Traversal: Only 0 NAT-D - Aborting NAT-Traversal negotiation"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #22: STATE_AGGR_R1: sent AR1, expecting AI2"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #22: transition from state STATE_AGGR_R0 to state STATE_AGGR_R1"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #22: responding to Aggressive Mode, state #22, connection ""aa"" from
> 113.89.241.123"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[2] 113.89.241.123
> #22: Aggressive mode peer ID is ID_FQDN: '@test26'"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.241.123:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-00]"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.241.123:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but already using method 109"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.241.123:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 109"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.241.123:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-03] meth=108, but already using method 109"
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.241.123:500: received Vendor ID payload [RFC 3947] method set
> to=109 "
> 17:07:28,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.241.123:500: received Vendor ID payload [Dead Peer Detection]"
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[1] 113.89.243.199
> #21: sending notification INVALID_ID_INFORMATION to 113.89.243.199:500"
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[1] 113.89.243.199
> #21: initial Aggressive Mode packet claiming to be from @test26 on
> 113.89.243.199 but no connection has been authorized"
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[1] 113.89.243.199
> #21: no suitable connection for peer '@test901'"
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"""aa""[1] 113.89.243.199
> #21: Aggressive mode peer ID is ID_FQDN: '@test901'"
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-00]"
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-02] meth=107, but already using method 109"
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, but already using method 109"
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload
> [draft-ietf-ipsec-nat-t-ike-03] meth=108, but already using method 109"
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload [RFC 3947] method set
> to=109 "
> 17:07:24,,secur/auth,Warning,pluto[9357],SSLVPN,"packet from
> 113.89.243.199:500: received Vendor ID payload [Dead Peer Detection]"
>
> 2009/6/23 Paul Wouters <paul at xelerance.com>
>
> On Tue, 23 Jun 2009, Zhiping Liu wrote:
>>
>> openswan 2.6.21 restart for serveral minutes. i found some error message
>>> from syslog:
>>>
>>> !pluto failure!: exited with error status 128
>>>
>>> and then openswan restarted itself.
>>>
>>
>> There should be more logs in /var/log/secure or /var/log/auth.log telling
>> you what is going on.
>>
>> Alternatively, you can define dumpdir=/var/run/pluto/ and make it crash
>> again, and then you have a core file in /var/run/pluto which you can
>> inspect with gdb.
>>
>> Paul
>>
>
>
>
> --
> from Romeo
>
--
from Romeo
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.openswan.org/pipermail/users/attachments/20090625/e0eaa15a/attachment-0001.html
More information about the Users
mailing list