[vpn-help] SAs expire immediately, connecting to Juniper SSG via Shrew

[Tim Keane]

Kevin VPN <kvpn at ...> writes:

> 
> On 10/27/2011 04:22 PM, Tim Keane wrote:
> >
> > When I attempt to connect using Shrew, Phase1 and Phase2 negotiations are
> > completed successfully.  However, the SAs immediately expire.  This is
> > happening using Shrew v. 2.1.7 and 2.2.0, on both XP and Win7 client 
> > computers.

> >
> 
> Hi Tim,
> 
> I would suggest that your problem is that Phase 2 is not completing 
> successfully.  Shrew might think that it's complete (mature), but the 
> gateway is still sending configure packets, suggesting that it does not 
> agree.  I've seen this before, but can't remember exactly the cause. 
> Maybe the proxy ids or policies didn't match?
> 
> Double-check your Phase 2, proxy and/or policy settings to be sure they 
> are the same on both the client and gateway.
> 

I've double-checked them, and I can't find any discrepancy.  If I watch the
Security Associations tab of the VPN Trace utility, I see two mature SAs
momentarily displayed.  The logs of the Juniper seem to indicate that it's happy
with the completion of the VPN tunnel as well.  I think my phase2 parameters
have to match, because the tunnel is up for a moment.

Any help with this would be much appreciated.  It's currently holding up our VPN
rollout, because I'd much rather get Shrew working than pay NCP's exhorbitant
prices for a client.  Thanks for anyone's help with this!


Here is the part of the log in question:

11/11/21 16:25:27 K> : send pfkey GETSPI ESP message
11/11/21 16:25:27 ii : phase2 ids accepted
11/11/21 16:25:27 ii : - loc ANY:192.168.107.128:* -> ANY:0.0.0.0/0:*
11/11/21 16:25:27 ii : - rmt ANY:0.0.0.0/0:* -> ANY:192.168.107.128:*
11/11/21 16:25:27 K< : recv pfkey GETSPI ESP message
11/11/21 16:25:27 DB : phase2 found
11/11/21 16:25:27 ii : phase2 sa established
11/11/21 16:25:27 ii : 1.2.3.112:500 <-> 1.2.3.8:500
11/11/21 16:25:27 == : phase2 hash_p ( input ) ( 57 bytes )
11/11/21 16:25:27 == : phase2 hash_p ( computed ) ( 20 bytes )
11/11/21 16:25:27 >> : hash payload
11/11/21 16:25:27 >= : cookies 233fbcc95807acf3:fe4dca22bc0e3bd5
11/11/21 16:25:27 >= : message a5755c05
11/11/21 16:25:27 >= : encrypt iv ( 16 bytes )
11/11/21 16:25:27 == : encrypt packet ( 52 bytes )
11/11/21 16:25:27 == : stored iv ( 16 bytes )
11/11/21 16:25:27 DB : phase2 resend event canceled ( ref count = 1 )
11/11/21 16:25:27 -> : send IKE packet 1.2.3.112:500 -> 1.2.3.8:500 ( 88 bytes )
11/11/21 16:25:27 == : PFS DH shared secret ( 128 bytes )
11/11/21 16:25:27 == : spi cipher key data ( 16 bytes )
11/11/21 16:25:27 == : spi hmac key data ( 20 bytes )
11/11/21 16:25:27 K> : send pfkey UPDATE ESP message
11/11/21 16:25:27 K< : recv pfkey UPDATE ESP message
11/11/21 16:25:27 == : spi cipher key data ( 16 bytes )
11/11/21 16:25:27 == : spi hmac key data ( 20 bytes )
11/11/21 16:25:27 K> : send pfkey UPDATE ESP message
11/11/21 16:25:27 <- : recv IKE packet 1.2.3.8:500 -> 1.2.3.112:500 ( 76 bytes )
11/11/21 16:25:27 DB : phase1 found
11/11/21 16:25:27 ii : processing phase2 packet ( 76 bytes )
11/11/21 16:25:27 DB : phase2 found
11/11/21 16:25:27 !! : phase2 packet ignored, resending last packet ( phase2
already mature )
11/11/21 16:25:27 -> : resend 1 phase2 packet(s) [0/2] 1.2.3.112:500 ->
1.2.3.8:500
11/11/21 16:25:27 <- : recv IKE packet 1.2.3.8:500 -> 1.2.3.112:500 ( 76 bytes )
11/11/21 16:25:27 DB : phase1 found
11/11/21 16:25:27 ii : processing phase2 packet ( 76 bytes )
11/11/21 16:25:27 DB : phase2 found
11/11/21 16:25:27 !! : phase2 packet ignored, resending last packet ( phase2
already mature )
11/11/21 16:25:27 -> : resend 1 phase2 packet(s) [1/2] 1.2.3.112:500 ->
1.2.3.8:500
11/11/21 16:25:27 <- : recv IKE packet 1.2.3.8:500 -> 1.2.3.112:500 ( 76 bytes )
11/11/21 16:25:27 DB : phase1 found
11/11/21 16:25:27 ii : processing phase2 packet ( 76 bytes )
11/11/21 16:25:27 DB : phase2 found
11/11/21 16:25:27 !! : phase2 packet ignored, resending last packet ( phase2
already mature )
11/11/21 16:25:27 -> : resend 1 phase2 packet(s) [2/2] 1.2.3.112:500 ->
1.2.3.8:500
11/11/21 16:25:27 K< : recv pfkey UPDATE ESP message
11/11/21 16:25:27 <- : recv IKE packet 1.2.3.8:500 -> 1.2.3.112:500 ( 76 bytes )
11/11/21 16:25:27 DB : phase1 found
11/11/21 16:25:27 ii : processing phase2 packet ( 76 bytes )
11/11/21 16:25:27 DB : phase2 found
11/11/21 16:25:27 !! : phase2 packet ignored, resending last packet ( phase2
already mature )
11/11/21 16:25:27 ii : resend limit exceeded for phase2 exchange
11/11/21 16:25:27 DB : phase2 soft event canceled ( ref count = 2 )
11/11/21 16:25:27 DB : phase2 hard event canceled ( ref count = 1 )
11/11/21 16:25:27 DB : phase1 found
11/11/21 16:25:27 ii : sending peer DELETE message