couchdb-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Nathan Vander Wilt <nate-li...@calftrail.com>
Subject Sporadic _session/_users lookup failures
Date Sat, 17 Nov 2012 19:41:22 GMT
I'm trying to diagnose an issue we're having with users getting unexpectedly logged out of
an app. This is affecting real-world use, interrupting work when our heartbeat check unexpectedly
detects the API is unusable.

I've reduced this to a test script I can run. The setup is as follows:
- set _config/couch_httpd_auth/timeout to 90
- run a script that logs in, then refreshes the AuthSession cookie every 30 seconds via /_session

What happens is shown below. After just a few or perhaps a whole lot of correct responses
to the _session request, all of a sudden the user appears to be logged out!

```
Logged in.      AuthSession=YWxpY2U6NTBBN0RBMjE6zpoSjz9lYJJ1tse3bpTvuS7H84Q

Sending cookie: AuthSession=YWxpY2U6NTBBN0RBMjE6zpoSjz9lYJJ1tse3bpTvuS7H84Q at 2012-11-17T18:41:09.250Z
 Recv'd cookie: AuthSession=YWxpY2U6NTBBN0RBM0Y6SqE-uad8GVVtE5nwLk5Woh6pW0U
{"ok":true,"userCtx":{"name":"alice","roles":["student","teacher"]},"info":{"authentication_db":"_users","authentication_handlers":["oauth","cookie","default"],"authenticated":"cookie"}}

// seemingly random duration passes, script often continues logging every 30 seconds for a
while…

Sending cookie: AuthSession=YWxpY2U6NTBBN0RDQjU66jE52YKejdDLVZZ_N5oPL74Gsl0 at 2012-11-17T18:52:09.250Z
 Recv'd cookie: AuthSession=YWxpY2U6NTBBN0RDRDM6Ogig0a9RpBMdZ4hHjHuet2KKurI
{"ok":true,"userCtx":{"name":"alice","roles":["student","teacher"]},"info":{"authentication_db":"_users","authentication_handlers":["oauth","cookie","default"],"authenticated":"cookie"}}


Sending cookie: AuthSession=YWxpY2U6NTBBN0RDRDM6Ogig0a9RpBMdZ4hHjHuet2KKurI at 2012-11-17T18:52:39.250Z
{"ok":true,"userCtx":{"name":null,"roles":[]},"info":{"authentication_db":"_users","authentication_handlers":["oauth","cookie","default"]}}



/Users/natevw/Desktop/Clients/Inquirium/readi-sensemaker-prototype/backend/session_test.js:33
        if (!~d.data.indexOf('alice')) throw "Logged out!";
                                       ^
Logged out!
```

The last cookie sent still has signed session data "alice:50A7DCD3" (2012-11-17T18:52:03Z
timestamp on server) which should still be valid for about another minute at the time of request.
But there is no "authenticated" field and "userCtx.name" turns up `null`! Why would this be?


To add to the intrigue, I just received a report of some (at first glance unrelated) initial
login trouble. Inspecting the logs, I found this:

GET /_users/org.couchdb.user%3Abob 404
GET /_users/org.couchdb.user%3Abob 404
// … time passes, with no intervening PUT/POST requests to the _users DB
GET /_users/org.couchdb.user%3Abob 200

This document would have been accessed using cookie credentials for user `bob`...again we
see an intermittent issue with either looking up a user or retaining a logged in state. (In
this case the cookie would have been only a few millseconds old.)


I strongly suspect this is a bug somewhere within CouchDB's the cookie handling path, or user
lookup path — but what and where in the code could be going wrong? Testing so far has been
against 1.2.0 as deployed on Iris Couch.

thanks,
-natevw
Mime
View raw message