View Issue Details
|ID||Project||Category||View Status||Date Submitted||Last Update|
|0005031||Taler||bank (demonstrator)||public||2017-05-24 23:36||2017-06-06 14:18|
|Reporter||Christian Grothoff||Assigned To||Marcello Stanisci|
|Platform||i7||OS||Debian GNU/Linux||OS Version||squeeze|
|Product Version||SVN HEAD|
|Target Version||0.3||Fixed in Version||0.3|
|Summary||0005031: bank logs: "Session data corrupted"|
|Description||I just launched a bank, logged in. No actual wallet operations. The logs say:|
*** Operational MODE: single process ***
2017-05-24 21:34:40,368 settings INFO DJANGO_SETTINGS_MODULE: talerbank.settings
2017-05-24 21:34:40,370 settings INFO secret key not configured in TALER_BANK_SECRET_KEY env variable, generating random secret
2017-05-24 21:34:40,371 settings INFO dbname: postgres:///talerbank
2017-05-24 21:34:40,371 settings INFO currency: 'KUDOS'
WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x55f9401de470 pid: 13669 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 13669)
spawned uWSGI worker 1 (pid: 13676, cores: 1)
spawned uWSGI http 1 (pid: 13677)
24/May/2017:21:34:59 +0000 HTTP/1.1 GET / HTTP/1.1 => 302
Session data corrupted
2017-05-24 21:34:59,588 base WARNING Session data corrupted
24/May/2017:21:34:59 +0000 HTTP/1.1 GET /profile HTTP/1.1 => 302
Session data corrupted
2017-05-24 21:34:59,599 base WARNING Session data corrupted
24/May/2017:21:34:59 +0000 HTTP/1.1 GET /login/?next=/profile HTTP/1.1 => 200
24/May/2017:21:34:59 +0000 HTTP/1.1 GET /static/pure.css HTTP/1.1 => 200
24/May/2017:21:34:59 +0000 HTTP/1.1 GET /static/web-common/demo.css HTTP/1.1 => 200
24/May/2017:21:34:59 +0000 HTTP/1.1 GET /static/web-common/taler-fallback.css HTTP/1.1 => 200
24/May/2017:21:34:59 +0000 HTTP/1.1 GET /static/web-common/taler-wallet-lib.js HTTP/1.1 => 200
24/May/2017:21:34:59 +0000 HTTP/1.1 GET /favicon.ico HTTP/1.1 => 200
24/May/2017:21:35:01 +0000 HTTP/1.1 GET /accounts/register/ HTTP/1.1 => 200
24/May/2017:21:35:01 +0000 HTTP/1.1 GET /favicon.ico HTTP/1.1 => 200
Session data corrupted
2017-05-24 21:35:04,188 base WARNING Session data corrupted
|Tags||No tags attached.|
Eh, this is pretty normal. When the bank starts, it generates a secret to encrypt cookies (all done automatically by django). We could persist this secret somewhere, but that's IMHO not necessary.
All that this leads to is that the user needs to re-authenticate every time the bank restarts, which is very reasonable.
Well, there are two bad things here still:
1) We log the warning twice, in fact many more times, but each time twice;
2) We log an incomprehensible warning. If it is truly harmless, it should not be this scary or suppressed.
Overall, I'm fine with not storing the secret to encrypt the cookies, but I don't understand why I get it for more than just the first connection after restart, that does suggests the issue is more serious. If it was just the restart, then a fresh cookie should have been set after the 1st connection and the subsequent requests should not generate the message, right?
I would expect that Django logs the warning more than once, because we log it for every HTTP request the browser makes until we manage to log in again. Cookies are sent with every request.
It does not go away after the first request, because the response to this request doesn't set any cookie.
Of course Django could have logic to clear a corrupted session cookie, but they decided not to do that. Django could also log a less scary warning, but they decided not to. There's nothing reasonable we can do here, other than to persist the secret.
||Note that in the logs above, the warning gets printed exactly for every request that is handled by django views (and not by static files). So Django just automatically tries to decrypt the cookie here ...|
||Well, if we can't easily do something about the logs, then I guess this is done.|
|2017-05-24 23:36||Christian Grothoff||New Issue|
|2017-05-24 23:36||Christian Grothoff||Status||new => assigned|
|2017-05-24 23:36||Christian Grothoff||Assigned To||=> Marcello Stanisci|
|2017-05-27 15:10||Florian Dold||Status||assigned => resolved|
|2017-05-27 15:10||Florian Dold||Resolution||open => fixed|
|2017-05-27 15:10||Florian Dold||Note Added: 0012162|
|2017-05-28 12:45||Christian Grothoff||Note Added: 0012163|
|2017-05-28 12:45||Christian Grothoff||Status||resolved => feedback|
|2017-05-28 12:45||Christian Grothoff||Resolution||fixed => reopened|
|2017-05-28 13:02||Florian Dold||Note Added: 0012164|
|2017-05-28 13:05||Florian Dold||Note Added: 0012165|
|2017-05-28 14:15||Christian Grothoff||Status||feedback => assigned|
|2017-05-28 14:15||Christian Grothoff||Resolution||reopened => no change required|
|2017-05-28 14:15||Christian Grothoff||Fixed in Version||=> 0.3|
|2017-05-28 14:15||Christian Grothoff||Note Added: 0012166|
|2017-05-28 14:16||Christian Grothoff||Status||assigned => resolved|
|2017-05-28 14:16||Christian Grothoff||Resolution||no change required => fixed|
|2017-06-06 14:18||Christian Grothoff||Status||resolved => closed|