[Openswan Users] !pluto failure!: exited with error status 128

Thu Jun 25 05:19:39 EDT 2009

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]"
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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.openswan.org/pipermail/users/attachments/20090625/927a6e30/attachment-0001.html 