search

hippich / Bitcoin-Poker-Room

Sources for Bitcoin Poker Room.
http://betco.in
Other
132 stars 87 forks source link

Server lockups #60

Closed hippich closed 13 years ago

hippich commented 13 years ago

Before server lockups completely, I can see following errors in the log:

2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] PokerResource: ERROR (x-forwarded-for:24.168.252.202) Traceback (most recent call last): 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/python2.6/dist-packages/twisted/web/server.py", line 132, in render 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] body = resrc.render(self) 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/python2.6/dist-packages/pokernetwork/pokersite.py", line 233, in render 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] deferred.addCallback(lambda result: self.deferRender(request, jsonp, packet, data)) 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py", line 224, in addCallback 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] callbackKeywords=kw) 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py", line 213, in addCallbacks 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] self._runCallbacks() 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] --- --- 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py", line 371, in _runCallbacks 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] self.result = callback(self.result, _args, *_kw) 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/python2.6/dist-packages/pokernetwork/pokersite.py", line 233, in 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] deferred.addCallback(lambda result: self.deferRender(request, jsonp, packet, data)) 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/python2.6/dist-packages/pokernetwork/pokersite.py", line 243, in deferRender 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] session = request.getSession() 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/python2.6/dist-packages/pokernetwork/pokersite.py", line 112, in getSession 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] self.session = self.site.getSession(uid, auth, explain) 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/python2.6/dist-packages/pokernetwork/pokersite.py", line 516, in getSession 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] memcache_serial = self.memcache.get(auth) 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/pymodules/python2.6/memcache.py", line 698, in get 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] check_key(key) 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] File "/usr/lib/pymodules/python2.6/memcache.py", line 983, in check_key 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] raise Client.MemcachedKeyNoneError, ("Key is None") 2011-06-24 06:51:40+0000 [HTTPChannel,13580,127.0.0.1] memcache.MemcachedKeyNoneError: Key is None

And

2011-06-24 06:57:51+0000 [-] PokerResource: ERROR (x-forwarded-for:66.214.234.229) Traceback (most recent call last): 2011-06-24 06:57:51+0000 [-] File "/usr/lib/python2.6/dist-packages/twisted/internet/base.py", line 778, in runUntilCurrent 2011-06-24 06:57:51+0000 [-] call.func(_call.args, _call.kw) 2011-06-24 06:57:51+0000 [-] File "/usr/lib/python2.6/dist-packages/pokernetwork/pokeravatar.py", line 381, in longPollDeferredTimeout 2011-06-24 06:57:51+0000 [-] d.callback(packets) 2011-06-24 06:57:51+0000 [-] File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py", line 280, in callback 2011-06-24 06:57:51+0000 [-] self._startRunCallbacks(result) 2011-06-24 06:57:51+0000 [-] File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py", line 354, in _startRunCallbacks 2011-06-24 06:57:51+0000 [-] self._runCallbacks() 2011-06-24 06:57:51+0000 [-] --- --- 2011-06-24 06:57:51+0000 [-] File "/usr/lib/python2.6/dist-packages/twisted/internet/defer.py", line 371, in _runCallbacks 2011-06-24 06:57:51+0000 [-] self.result = callback(self.result, _args, _kw) 2011-06-24 06:57:51+0000 [-] File "/usr/lib/python2.6/dist-packages/pokernetwork/pokersite.py", line 256, in render 2011-06-24 06:57:51+0000 [-] session.site.persistSession(session) 2011-06-24 06:57:51+0000 [-] File "/usr/lib/python2.6/dist-packages/pokernetwork/pokersite.py", line 473, in persistSession 2011-06-24 06:57:51+0000 [-] if len(session.avatar.tables) <= 0 and len(session.avatar.tourneys) <= 0 and (not session.avatar.explain or len(session.avatar.explain.games.getAll()) <= 0): 2011-06-24 06:57:51+0000 [-] exceptions.AttributeError: Session instance has no attribute 'avatar'

anisoptera commented 13 years ago

50035 in the federation branch is a possible fix for the second one. I'll cherrypick it into master once I get to a machine.

A similar patch will probably fix the first one as well, I'll take a look - probably just need to catch that exception.

I'm bewildered that these were not an issue for the original codebase or no one noticed. My guess is that no one tested memcache expiring a session before - I can repro this on my local environment by leaving a user logged in for a long time.

anisoptera commented 13 years ago

Not closing this yet as I don't believe I've found the root cause - these seem like symptoms of a deeper problem.

Namely, how did we get a None auth string in the first place?

hippich commented 13 years ago

That's what bother me most of all.

This do not happen in the beginning at all. Then it start to happen sometimes (exception re: avatar attr) and when server locksup - every requests return this exception. Even if I fully log out, log in (i.e. new auth generated) and try to open table.

hippich commented 13 years ago

Seems to work stable. Closing for now.