View Issue Details

IDProjectCategoryView StatusLast Update
0005031Talerobsolete componentpublic2017-06-06 12:18
ReporterChristian Grothoff Assigned ToMarcello Stanisci Resolution deadline
ImplementerReviewer 
Release signed byDeployed by 
VerifierCommunicator 
Data protection authority notification requiredNo  
CSIRT notification requiredNo  
Estimated effort (hours)Actual effort (hours)0 
Fast-trackNo
Work packagenone
PrioritynormalSeverityminorReproducibilityalways
Status closedResolutionfixed 
Platformi7OSDebian GNU/LinuxOS Versionsqueeze
Product Versiongit (master) 
Target Version0.3Fixed in Version0.3 
Summary0005031: bank logs: "Session data corrupted"
DescriptionI 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
TagsNo tags attached.

Required notifications

Address or linkRemarkAdded byNotifiedActions

Activities

Florian Dold

2017-05-27 13:10

manager   ~0012162

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.

Christian Grothoff

2017-05-28 10:45

manager   ~0012163

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?

Florian Dold

2017-05-28 11:02

manager   ~0012164

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.

Florian Dold

2017-05-28 11:05

manager   ~0012165

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 ...

Christian Grothoff

2017-05-28 12:15

manager   ~0012166

Well, if we can't easily do something about the logs, then I guess this is done.

Issue History

Date ModifiedUsernameFieldChange
2017-05-24 21:36Christian GrothoffNew Issue
2017-05-24 21:36Christian GrothoffStatusnew => assigned
2017-05-24 21:36Christian GrothoffAssigned To => Marcello Stanisci
2017-05-27 13:10Florian DoldStatusassigned => informing
2017-05-27 13:10Florian DoldResolutionopen => fixed
2017-05-27 13:10Florian DoldNote Added: 0012162
2017-05-28 10:45Christian GrothoffNote Added: 0012163
2017-05-28 10:45Christian GrothoffStatusinforming => feedback
2017-05-28 10:45Christian GrothoffResolutionfixed => reopened
2017-05-28 11:02Florian DoldNote Added: 0012164
2017-05-28 11:05Florian DoldNote Added: 0012165
2017-05-28 12:15Christian GrothoffStatusfeedback => assigned
2017-05-28 12:15Christian GrothoffResolutionreopened => no change required
2017-05-28 12:15Christian GrothoffFixed in Version => 0.3
2017-05-28 12:15Christian GrothoffNote Added: 0012166
2017-05-28 12:16Christian GrothoffStatusassigned => informing
2017-05-28 12:16Christian GrothoffResolutionno change required => fixed
2017-06-06 12:18Christian GrothoffStatusinforming => closed
2022-08-23 18:26Christian GrothoffCategorybank (demonstrator) => py bank (demonstrator, obsolete)
2023-12-03 00:23Christian GrothoffCategorypy bank (demonstrator, obsolete) => obsolete componet
2023-12-11 19:08Florian DoldCategoryobsolete componet => obsolete component