Warning: Can't synchronize with repository "(default)" (Unsupported version control system "svn": No module named svn). Look in the Trac log for more information.

Ticket #2346 (closed defect: fixed)

Opened 8 years ago

Last modified 8 years ago

Visit expires even though the user had accessed before expiry time

Reported by: mitsuru.oka Owned by: chrisz
Priority: low Milestone: 1.0.x bugfix
Component: TurboGears Version: 1.0.8
Severity: normal Keywords: needs patch, visit
Cc:

Description

On following condition, visit may expires even though the user had accessed before expiry time T2+60.

  • app.cfg: visit.time = 60
  • User first accessed at T1. The expiry time should be T1+60.
  • User second accessed at T2 = T1+50 < T1+60. This update the expiry time that should be T2+60.
  • User third accessed at T3 = T2+20 < T2+60. However, this often cause the visit expire.

This is because (SqlObject?|SqlAlchemy?)VisitManager? does not check self.queue cache before lookup visit_class data source, which has expired visit record until self.update_queued_visits will be called.

Change History

comment:1 Changed 8 years ago by Chris Arndt

  • Owner set to Chris Arndt
  • Keywords needs patch, visit added
  • Milestone changed from 1.x to 1.0.x bugfix

This should be easy to fix, but it also seems to me, that this could be easily worked around with setting "visit.timeout" to a small enough value.

comment:2 Changed 8 years ago by Chris Arndt

  • Owner changed from Chris Arndt to chrisz

comment:3 Changed 8 years ago by chrisz

@ChrisA: You probably mean BaseVisitManager.interval, not visit.timeout. That interval was not yet configurable, but I made it configurable now in r6751 via the new visit.interval setting. The default is 30 seconds.

@mitsuru.oka: You probably mean visit.timeout, not visit.time. This setting is in minutes. Since the visit manager interval is much smaller than 10 minutes, it would not happen under the conditions you described. However, the basic problem analysis is correct. The described problem can happen if T3-T2 < 0.5 and T2 < T1+60 < T3. E.g. T2 = T1+59.8 and T3 = T1+60.2.

In practice this means it can happen that the user would issue a request after waiting for a long time very close to the timeout and it works, then some seconds later he tries again but is logged off. That would be in fact confusing. Making visit.interval smaller and visit.timeout larger reduces the probability for this to happen, but never gets it to zero. So maybe we need to solve this more properly.

comment:4 Changed 8 years ago by Chris Arndt

As the OP already hinted at, SQLObject|AlchemyVisitManager.visit_for_key should check if visit_key is in self.queue and, if yes, use the expiry time from there. E.g.

        visit = visit_class.lookup_visit(visit_key)
        if not visit:
            return None

        now = datetime.now(visit.expiry.tzinfo)
        expiry = self.queue.get(visit_key) or visit.expiry
        if expiry < now:
            return None

I don't think we need to lock self.queue just for reading it though there might be a minimal chance for a race condition, so we might as well.

comment:5 Changed 8 years ago by Chris Arndt

Also, please open a documentation ticket for the new config setting.

comment:6 follow-up: ↓ 7 Changed 8 years ago by chrisz

Ok, I have not fixed this as suggested by mitsuru.oka (for TG 1.1 in r6752, for TG 1.0 in r6753). Dictionary lookups are thread-safe, so we don't need a lock.

You can easily reproduce the problem and check the fix for it by setting visit.timeout=1 and visit.interval=120.

If I mention the new setting in the TG 1 doc wiki and add a changelog entry, that would be sufficient, I suppose?

comment:7 in reply to: ↑ 6 Changed 8 years ago by Chris Arndt

Replying to chrisz:

Dictionary lookups are thread-safe, so we don't need a lock.

I see you look up the visit_key in self.queue first, so the race condition I was thinking would not occur.

If I mention the new setting in the TG 1 doc wiki and add a changelog entry, that would be sufficient, I suppose?

Yes.

comment:8 Changed 8 years ago by chrisz

  • Status changed from new to closed
  • Resolution set to fixed

Ok, I've mentioned it in the changelog and in the  Wiki now.

Note: See TracTickets for help on using tickets.