On Mon, Apr 13, 2020 at 5:12 PM The Wanderer <wanderer@xxxxxxxxxxx> wrote: > On 2020-04-13 at 19:50, Daniel Lenski wrote: > > > On Mon, Apr 13, 2020 at 4:35 PM The Wanderer <wanderer@xxxxxxxxxxx> > > wrote: > > > >> I'm currently running OpenConnect 8.08, installed via the package > >> available in Debian testing. > >> > >> Until a few days ago or so, I was running version 8.05, which was > >> at that time the latest available in Debian testing. > >> > >> Prior to that (for at most a week at the end of March), I was > >> apparently running version 8.0.2, again installed via Debian > >> testing. > >> > >> > >> I am connecting to a GlobalProtect VPN, and using that to RDP to a > >> Windows machine (via XFreeRDP), for eight hours or so a day. (You > >> can probably guess why.) > >> > >> Prior to one of the version upgrades described above, I was able > >> to remain connected for the entire period, without significant > >> issues. I did not pay close enough attention to be certain which > >> one, but I believe it was the transition from 8.05 to 8.08. > >> > >> After the upgrade, I appear to be seeing the connection drop every > >> three hours to the minute - although not quite to the second; it > >> seems to be something between 18 and ~45 seconds past the exact > >> three-hour mark when the drop happens. I haven't tried to get this > >> in any more detail than that, as of yet. > >> > >> According to the log which I generate by appending openconnect's > >> stdout and (theoretically) stderr into a file, the "Tunnel timeout > >> (rekey interval) and "Idle timeout" are both 180 minutes, which is > >> that three hours. > > > > Good sleuthing so far. > > > > However, there were *no changes* to the handling of rekey between > > v8.05 and v8.08 (at least none intended): > > https://gitlab.com/openconnect/openconnect/-/compare/v8.05...v8.08#efecf80fa476ca5abf1502940e60d7984c6d1df9 > > > > There were *also* no intentional changes to the handling of rekey > > between v8.02 and v8.08: > > > > https://gitlab.com/openconnect/openconnect/-/compare/v8.02...v8.08#efecf80fa476ca5abf1502940e60d7984c6d1df9 > > And I gather that there's no plausible way the idle timeout could be > involved - e.g. with something mistakenly thinking we've been idle for > the entire time, instead of having had ongoing active traffic? Not unless it was a change on the *server* side. And probably doesn't matter anyway… if we find out that OpenConnect isn't rekeying as expected at the 3 hour mark, then we know that's the problem. Seems a lot more likely. > > This particular one has already been reported; we still don't > > understand what it means, but it's very common. ¯\_(ツ)_/¯ > > I saw some of those discussions in looking at the archives before I > reported this. If I get a chance to figure out what that means, I'll be > sure to pass any (visibly) potentially relevant information along. Sounds good. One of the main *interesting* mysteries concerns IPv6. > >> Anything I can do to help track this down? So far none of these > >> connection drops have been timed to be a practical problem, but at > >> some point one is going to come while I'm in the middle of a voice > >> or even video call across the VPN, and that's going to be > >> noticeable. > > > > Run it with `openconnect -vvvv --dump --timestamp`, and save that to > > a file. The log size may be huge after ~3 hours, but it'll give you > > precise timestamps for all messages. > > How huge are we talking about? A few hundred megabytes? A few gigabytes? ¯\_(ツ)_/¯ Depends how much you use it. It will print one log line for every incoming and outgoing packet over the VPN. We really only need the log lines from right around the time the connection is established… and then 2 hours and 59 minutes later when OpenConnect *should* be triggering the rekey. If you can wire things up to discard the intervening logs, go for it. But we definitely need to see what happens during the minute or two after that, because that's where something might be going wrong. > > One of the messages that you should be looking for shortly before > > the 3 hour mark is "GlobalProtect rekey due." > > That's showing up in the logs I have already, but there's no apparently > relevant information in the logs around that, presumably because I'm > only at default verbosity. Good that it's showing up. Yeah, if you crank the verbosity way up then you should see a lot more. What we expect to see is the connection being torn down, set back up, new ESP encryption keys being acquired. Since it's *not* working, the exact form of failure detection will also be interesting… is it a DPD? is it some unexpected packet? etc. -Dan _______________________________________________ openconnect-devel mailing list openconnect-devel@xxxxxxxxxxxxxxxxxxx http://lists.infradead.org/mailman/listinfo/openconnect-devel
