Mailing List Archive: vpnc: devel

Regular phase2_fatal error every 57minutes and 40 seconds

Index | Next | Previous | View Threaded

mthomson at sunwave

Dec 18, 2008, 9:04 AM

Post #1 of 6 (1395 views)
Permalink

Regular phase2_fatal error every 57minutes and 40 seconds

Hi,

I have been using VPNC on vista 64 bit for a while now and I am getting
a new issue, which I was wondering if anyone has already experienced.

Basically I would get the occasional dropout every now and then and
didn't think much of it assuming it was just my fragile cable provider
having a hiccup.

But recently I have been doing some larger downloads and started to
notice that the timing seemed very "regular".

I am now running vpnc in "time" and I see that it fails very regularly.

I decided I should move to the latest release to see if the problem had
already been fixed so moved to 0.5.3

I still get the failure every 57m 40secs but now I get nice message as
follows:

---!!!!!!!!! entering phase2_fatal !!!!!!!!!---

quick mode response rejected: (ISAKMP_N_INVALID_PAYLOAD_TYPE)(1)
this means the concentrator did not like what we had to offer.
Possible reasons are:
* concentrator configured to require a firewall
this locks out even Cisco clients on any platform expect windows
which is an obvious security improvment. There is no workaround (yet).
* concentrator configured to require IP compression
this is not yet supported by vpnc.
Note: the Cisco Concentrator Documentation recommends against using
compression, expect on low-bandwith (read: ISDN) links, because it
uses much CPU-resources on the concentrator

I had a look around on mailing list and could not really see anything
pertaining to my 57 minute event. I noticed others got this issue when
they initially tried to connect.

I did read about a maximum 8 hr connection, I an wondering if perhaps
the admins have set up a 1hr max connection? Our IT people are not very
forthcoming with info, as I believe they contract out the config etc.

Hoping someone can recommend something I can try to solve this issue?

P.S. Tried connecting from an XP machine using the CISCO client and had
no issues at 57 minutes from within same network.

Thanks in advance
Michael.
_______________________________________________
vpnc-devel mailing list
vpnc-devel [at] unix-ag
https://lists.unix-ag.uni-kl.de/mailman/listinfo/vpnc-devel
http://www.unix-ag.uni-kl.de/~massar/vpnc/

mr-vpnc at webdeck

Dec 18, 2008, 7:27 PM

Post #2 of 6 (1396 views)
Permalink

Re: Regular phase2_fatal error every 57minutes and 40 seconds [In reply to]

I'm seeing that same error message, but at random times during my
connection, not consistently like you are seeing it, sometimes it
happens hours after I started vpnc - I haven't been able to run more
than about 8 hours consistently without it erroring out. In contrast,
the Cisco VPN client has been able to run for months without
interruption. I'm running 0.5.3 on Mac OS X 10.5.5, connecting to a
Cisco device (I don't know the specifics...) Here is what I see -
this time it happened right around rekeying, it looks like:

lifetime status: 27350 of 28800 seconds used, 9994|1403 of 0 kbytes
used
lifetime status: 27359 of 28800 seconds used, 9994|1403 of 0 kbytes
used
lifetime status: 27359 of 28800 seconds used, 9994|1403 of 0 kbytes
used
got late ike paket: 348 bytes
got paket with wrong cookies
lifetime status: 27359 of 28800 seconds used, 9994|1403 of 0 kbytes
used
got late ike paket: 148 bytes
got ipsec lifetime attributes: 28800 seconds
lifetime status: 4 of 28800 seconds used, 0|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 0|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 0|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 0|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 0|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 0|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 1|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 2|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 2|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 2|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 4|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 4|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 5|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 5|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 7|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 7|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 8|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 8|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 9|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 11|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 11|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 11|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 12|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 12|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 13|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 13|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 15|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 15|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 15|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 15|0 of 0 kbytes used
lifetime status: 4 of 28800 seconds used, 15|0 of 0 kbytes used
lifetime status: 8 of 28800 seconds used, 15|0 of 0 kbytes used
got late ike paket: 348 bytes
got paket with wrong cookies
lifetime status: 9 of 28800 seconds used, 15|0 of 0 kbytes used
lifetime status: 16 of 28800 seconds used, 15|0 of 0 kbytes used
got late ike paket: 348 bytes
got paket with wrong cookies
lifetime status: 18 of 28800 seconds used, 15|0 of 0 kbytes used
lifetime status: 24 of 28800 seconds used, 15|0 of 0 kbytes used
got late ike paket: 348 bytes
got paket with wrong cookies
lifetime status: 27 of 28800 seconds used, 15|0 of 0 kbytes used
lifetime status: 37 of 28800 seconds used, 15|0 of 0 kbytes used
lifetime status: 37 of 28800 seconds used, 15|0 of 0 kbytes used
got late ike paket: 68 bytes

S7.1 QM_packet1
[2008-12-18 12:26:58]

S7.2 QM_packet2 send_receive
[2008-12-18 12:26:58]

S7.3 QM_packet2 validate type
[2008-12-18 12:26:58]

S7.4 process and skip lifetime notice
[2008-12-18 12:26:58]

S7.5 QM_packet2 check reject offer
[2008-12-18 12:26:58]

---!!!!!!!!! entering phase2_fatal !!!!!!!!!---

quick mode response rejected: (ISAKMP_N_INVALID_PAYLOAD_TYPE)(1)
this means the concentrator did not like what we had to offer.
Possible reasons are:
* concentrator configured to require a firewall
this locks out even Cisco clients on any platform expect windows
which is an obvious security improvment. There is no workaround
(yet).
* concentrator configured to require IP compression
this is not yet supported by vpnc.
Note: the Cisco Concentrator Documentation recommends against using
compression, expect on low-bandwith (read: ISDN) links, because it
uses much CPU-resources on the concentrator

On Dec 18, 2008, at 9:04 AM, Michael Thomson wrote:

> Hi,
>
> I have been using VPNC on vista 64 bit for a while now and I am
> getting
> a new issue, which I was wondering if anyone has already experienced.
>
> Basically I would get the occasional dropout every now and then and
> didn't think much of it assuming it was just my fragile cable provider
> having a hiccup.
>
> But recently I have been doing some larger downloads and started to
> notice that the timing seemed very "regular".
>
> I am now running vpnc in "time" and I see that it fails very
> regularly.
>
> I decided I should move to the latest release to see if the problem
> had
> already been fixed so moved to 0.5.3
>
> I still get the failure every 57m 40secs but now I get nice message as
> follows:
>
> ---!!!!!!!!! entering phase2_fatal !!!!!!!!!---
>
>
> quick mode response rejected: (ISAKMP_N_INVALID_PAYLOAD_TYPE)(1)
> this means the concentrator did not like what we had to offer.
> Possible reasons are:
> * concentrator configured to require a firewall
> this locks out even Cisco clients on any platform expect windows
> which is an obvious security improvment. There is no workaround
> (yet).
> * concentrator configured to require IP compression
> this is not yet supported by vpnc.
> Note: the Cisco Concentrator Documentation recommends against
> using
> compression, expect on low-bandwith (read: ISDN) links, because it
> uses much CPU-resources on the concentrator
>
>
> I had a look around on mailing list and could not really see anything
> pertaining to my 57 minute event. I noticed others got this issue
> when
> they initially tried to connect.
>
> I did read about a maximum 8 hr connection, I an wondering if perhaps
> the admins have set up a 1hr max connection? Our IT people are not
> very
> forthcoming with info, as I believe they contract out the config etc.
>
> Hoping someone can recommend something I can try to solve this issue?
>
> P.S. Tried connecting from an XP machine using the CISCO client and
> had
> no issues at 57 minutes from within same network.
>
> Thanks in advance
> Michael.
> _______________________________________________
> vpnc-devel mailing list
> vpnc-devel [at] unix-ag
> https://lists.unix-ag.uni-kl.de/mailman/listinfo/vpnc-devel
> http://www.unix-ag.uni-kl.de/~massar/vpnc/

_______________________________________________
vpnc-devel mailing list
vpnc-devel [at] unix-ag
https://lists.unix-ag.uni-kl.de/mailman/listinfo/vpnc-devel
http://www.unix-ag.uni-kl.de/~massar/vpnc/

jmvpnc at loplof

Dec 21, 2008, 2:43 AM

Post #3 of 6 (1335 views)
Permalink

Re: Regular phase2_fatal error every 57minutes and 40 seconds [In reply to]

On Thu, Dec 18, 2008 at 09:04:43AM -0800, Michael Thomson wrote:
> I still get the failure every 57m 40secs but now I get nice message as
> follows:

> I did read about a maximum 8 hr connection, I an wondering if perhaps
> the admins have set up a 1hr max connection? Our IT people are not very
> forthcoming with info, as I believe they contract out the config etc.

It looks like you are correct with your assumption that the phase 2 timeout
is 1 hour in your case where others may have an 8 hour timeout.
You can find out about it by running vpnc --no-detach --debug 2 <profile>
and having a look at the output.
In case the timeout is 1h, please send me the output of
vpnc --no-detach --debug 3 <profile> (Note the 3 instead of the 2 above) for
the whole thing including the first successful phase 2 negotiation and the
(failing) last phase 2 rekeying.

ciao
Joerg
--
Joerg Mayer <jmayer [at] loplof>
We are stuck with technology when what we really want is just stuff that
works. Some say that should read Microsoft instead of technology.
_______________________________________________
vpnc-devel mailing list
vpnc-devel [at] unix-ag
https://lists.unix-ag.uni-kl.de/mailman/listinfo/vpnc-devel
http://www.unix-ag.uni-kl.de/~massar/vpnc/

mthomson at sunwave

Dec 21, 2008, 12:43 PM

Post #4 of 6 (1349 views)
Permalink

Re: Regular phase2_fatal error every 57minutes and 40 seconds [In reply to]

Joerg Mayer wrote:
> On Thu, Dec 18, 2008 at 09:04:43AM -0800, Michael Thomson wrote:
>
>> I still get the failure every 57m 40secs but now I get nice message as
>> follows:
>>
>
>
>> I did read about a maximum 8 hr connection, I an wondering if perhaps
>> the admins have set up a 1hr max connection? Our IT people are not very
>> forthcoming with info, as I believe they contract out the config etc.
>>
>
> It looks like you are correct with your assumption that the phase 2 timeout
> is 1 hour in your case where others may have an 8 hour timeout.
> You can find out about it by running vpnc --no-detach --debug 2 <profile>
> and having a look at the output.
> In case the timeout is 1h, please send me the output of
> vpnc --no-detach --debug 3 <profile> (Note the 3 instead of the 2 above) for
> the whole thing including the first successful phase 2 negotiation and the
> (failing) last phase 2 rekeying.
>
> ciao
> Joerg
>
Joerg,

Here is the tail of the debug 2 log, it seems to go bad at the pointg it
says "got packet with wrong cookie". I am producing the debug 3 log
right now

Thanks
Michael.

lifetime status: 3304 of 28800 seconds used, 192|194 of 0 kbytes used
lifetime status: 3306 of 28800 seconds used, 192|194 of 0 kbytes used
lifetime status: 3310 of 28800 seconds used, 192|195 of 0 kbytes used
lifetime status: 3319 of 28800 seconds used, 192|195 of 0 kbytes used
lifetime status: 3319 of 28800 seconds used, 192|195 of 0 kbytes used
lifetime status: 3328 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3338 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3342 of 28800 seconds used, 193|195 of 0 kbytes used
NAT-T mode, adding non-esp marker
lifetime status: 3342 of 28800 seconds used, 193|195 of 0 kbytes used
got late ike paket: 84 bytes
got r-u-there ack
lifetime status: 3343 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3352 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3361 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3371 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3373 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3373 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3373 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3374 of 28800 seconds used, 193|195 of 0 kbytes used
lifetime status: 3374 of 28800 seconds used, 193|196 of 0 kbytes used
lifetime status: 3376 of 28800 seconds used, 193|196 of 0 kbytes used
lifetime status: 3380 of 28800 seconds used, 193|196 of 0 kbytes used
lifetime status: 3389 of 28800 seconds used, 193|196 of 0 kbytes used
lifetime status: 3389 of 28800 seconds used, 193|196 of 0 kbytes used
lifetime status: 3398 of 28800 seconds used, 193|196 of 0 kbytes used
lifetime status: 3402 of 28800 seconds used, 193|196 of 0 kbytes used
lifetime status: 3403 of 28800 seconds used, 194|196 of 0 kbytes used
lifetime status: 3412 of 28800 seconds used, 194|196 of 0 kbytes used
lifetime status: 3421 of 28800 seconds used, 194|196 of 0 kbytes used
got late ike paket: 348 bytes
got paket with wrong cookies
lifetime status: 3429 of 28800 seconds used, 194|196 of 0 kbytes used
got late ike paket: 348 bytes
got paket with wrong cookies
lifetime status: 3437 of 28800 seconds used, 194|196 of 0 kbytes used
got late ike paket: 348 bytes
got paket with wrong cookies
lifetime status: 3445 of 28800 seconds used, 194|196 of 0 kbytes used
got late ike paket: 348 bytes
got paket with wrong cookies
lifetime status: 3453 of 28800 seconds used, 194|196 of 0 kbytes used
lifetime status: 3454 of 28800 seconds used, 194|196 of 0 kbytes used
lifetime status: 3454 of 28800 seconds used, 194|197 of 0 kbytes used
lifetime status: 3454 of 28800 seconds used, 194|197 of 0 kbytes used
lifetime status: 3454 of 28800 seconds used, 194|197 of 0 kbytes used
lifetime status: 3454 of 28800 seconds used, 194|197 of 0 kbytes used
lifetime status: 3457 of 28800 seconds used, 194|197 of 0 kbytes used
got late ike paket: 68 bytes

S7.1 QM_packet1
[2008-12-21 11:33:25]

S7.2 QM_packet2 send_receive
[2008-12-21 11:33:25]
NAT-T mode, adding non-esp marker

S7.3 QM_packet2 validate type
[2008-12-21 11:33:25]

S7.4 process and skip lifetime notice
[2008-12-21 11:33:25]

S7.5 QM_packet2 check reject offer
[2008-12-21 11:33:25]

---!!!!!!!!! entering phase2_fatal !!!!!!!!!---

NAT-T mode, adding non-esp marker
NAT-T mode, adding non-esp marker
_______________________________________________
vpnc-devel mailing list
vpnc-devel [at] unix-ag
https://lists.unix-ag.uni-kl.de/mailman/listinfo/vpnc-devel
http://www.unix-ag.uni-kl.de/~massar/vpnc/

massar at unix-ag

Dec 21, 2008, 1:13 PM

Post #5 of 6 (1334 views)
Permalink

Re: Regular phase2_fatal error every 57minutes and 40 seconds [In reply to]

hi,

On Sun, Dec 21, 2008 at 12:43:08PM -0800, Michael Thomson wrote:
> Joerg Mayer wrote:
> > It looks like you are correct with your assumption that the phase 2 timeout
> > is 1 hour in your case where others may have an 8 hour timeout.
> > You can find out about it by running vpnc --no-detach --debug 2 <profile>
> > and having a look at the output.
> > In case the timeout is 1h, please send me the output of
> > vpnc --no-detach --debug 3 <profile> (Note the 3 instead of the 2 above) for
> > the whole thing including the first successful phase 2 negotiation and the
> > (failing) last phase 2 rekeying.
>
> Here is the tail of the debug 2 log, it seems to go bad at the pointg it
> says "got packet with wrong cookie". I am producing the debug 3 log
> right now
[...]
> got late ike paket: 348 bytes
> got paket with wrong cookies
> lifetime status: 3429 of 28800 seconds used, 194|196 of 0 kbytes used
[...]

as vpnc will not decode/dump a packet with wrong cookies, please run a
tcpdump -s 65000 -w /tmp/trace.pcap ....
in parallel to the end of the session. You can use wireshark to extract
the relevant packets afterwards, and please mail it to vpnc [at] unix-a
(which is Joerg and me). Currently I suspect that the other side is
trying to initiate a phase1 aggresive-mode exchange, something which
vpnc does not know yet how to respond to.

cu
Maurice
_______________________________________________
vpnc-devel mailing list
vpnc-devel [at] unix-ag
https://lists.unix-ag.uni-kl.de/mailman/listinfo/vpnc-devel
http://www.unix-ag.uni-kl.de/~massar/vpnc/

massar at unix-ag

Dec 21, 2008, 3:07 PM

Post #6 of 6 (1341 views)
Permalink

Re: Regular phase2_fatal error every 57minutes and 40 seconds [In reply to]

hi,

On Sun, Dec 21, 2008 at 10:13:32PM +0100, Maurice Massar wrote:
> On Sun, Dec 21, 2008 at 12:43:08PM -0800, Michael Thomson wrote:
> > Joerg Mayer wrote:
> > > It looks like you are correct with your assumption that the phase 2 timeout
> > > is 1 hour in your case where others may have an 8 hour timeout.

$ zcat vpncDebug3.gz | fgrep 'lifetime attributes:'
got ike lifetime attributes: 2147483 seconds
got ike lifetime attributes: 3600 seconds
got ipsec lifetime attributes: 2147483 seconds
got ipsec lifetime attributes: 28800 seconds

the first line is always an echo of what vpnc proposes to the server.
The second line is the lifetime the server really wants. In this case
it is a phase2(IPSec) lifetime of 8 hours, and a phase1(ISAKMP) lifetime
of just 1 hour. But as the time for the IPSec connection is limited by
the ISAKMP connection the effective lifetime is 1 hour.

So it is missing phase1 rekeying support which is killing the connection
here.

> Currently I suspect that the other side is
> trying to initiate a phase1 aggresive-mode exchange, something which
> vpnc does not know yet how to respond to.

I'm curious about these wrong-cookies packets.. if the other side is
initiating a phase1 exchange here, vpnc will need some additional code
to handle this reversal of roles opposed to the initial connection..
Another interesting bit will be, if xauth needs to be done again in this
case or not ...

cu
maurice
_______________________________________________
vpnc-devel mailing list
vpnc-devel [at] unix-ag
https://lists.unix-ag.uni-kl.de/mailman/listinfo/vpnc-devel
http://www.unix-ag.uni-kl.de/~massar/vpnc/

Index | Next | Previous | View Threaded

Interested in having your list archived? Contact Gossamer Threads