search

ether / etherpad-lite

Etherpad: A modern really-real-time collaborative document editor.
http://docs.etherpad.org/
Apache License 2.0
16.08k stars 2.79k forks source link

session is reset multiple times [Chrome Specific?] #1659

Closed disy-mk closed 4 years ago

disy-mk commented 11 years ago

Every time accessing the same pad (reloading) creates 4 new 'sessionstorage' in my DB. This happens with public pads. Freshly cloned latest dev.

the log

_epl_dev$ bin/run.sh 
Ensure that all dependencies are up to date...  If this is the first time you have run Etherpad please be patient.
Ensure jQuery is downloaded and up to date...
Clear minfified cache...
ensure custom css/js files are created...
start...
[2013-03-23 19:51:08.563] [INFO] console - Installed plugins: ep_etherpad-lite, ep_headings
[2013-03-23 19:51:08.594] [INFO] console - Your Etherpad Lite git version is 35e4891
[2013-03-23 19:51:08.595] [INFO] console - Report bugs at https://github.com/ether/etherpad-lite/issues
[2013-03-23 19:51:08.600] [INFO] console - SSL -- enabled
[2013-03-23 19:51:08.600] [INFO] console - SSL -- server key file: /etc/ssl/private/share-test.uni-konstanz.de.key
[2013-03-23 19:51:08.600] [INFO] console - SSL -- Certificate Authority's certificate file: /etc/ssl/[...]
[2013-03-23 19:51:08.659] [INFO] console -    info  - 'socket.io started'
[2013-03-23 19:51:08.706] [INFO] console - You can access your Etherpad-Lite instance at http://0.0.0.0:9876/
[2013-03-23 19:51:08.706] [INFO] console - The plugin admin page is at http://0.0.0.0:9876/admin/plugins
[2013-03-23 19:51:36.803] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:37.221] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:42.175] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:43.584] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:43.784] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:43.884] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:46.324] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:46.525] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:46.624] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:46.725] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:47.025] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:47.126] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:47.142] [INFO] socket.io - handshake authorized 'ldes4Co7N1Dg31s_lwv0'
[2013-03-23 19:51:47.327] [INFO] access - [CREATE] Pad "test": Client ldes4Co7N1Dg31s_lwv0 with IP "#######" created the pad
[2013-03-23 19:51:47.332] [INFO] ueberDB - Flushed 6 values
[2013-03-23 19:51:47.432] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:47.532] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:51:47.632] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:52:32.756] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:52:32.857] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:52:32.956] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:52:33.043] [INFO] socket.io - handshake authorized 'x0_0FDtgGFC3jjoglwv1'
[2013-03-23 19:52:33.056] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:52:33.202] [INFO] access - [CREATE] Pad "test": Client x0_0FDtgGFC3jjoglwv1 with IP "########" created the pad
[2013-03-23 19:52:33.257] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:52:33.358] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:52:33.659] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:52:33.858] [INFO] ueberDB - Flushed 1 values
[2013-03-23 19:52:33.959] [INFO] ueberDB - Flushed 2 values
JohnMcLear commented 11 years ago

Take a look at https://github.com/ether/etherpad-lite/pull/1623

disy-mk commented 11 years ago

Ah, k , thought it just was related to node v0.10; cause didn't get response on #1526 regarding that

JohnMcLear commented 11 years ago

@disy-mk Does this problem persist w/ 1623?

marcelklehr commented 11 years ago

@disy-mk could you post the same with logging on debug level?

disy-mk commented 11 years ago

Let's see:

Damn it, i'll repost with debug level soon

@marcelklehr:

pg@0.14.1 install /home/epl/_epl_129/src/node_modules/ueberDB/node_modules/pg node-gyp rebuild || (exit 0)

You need to install postgresql-server-dev-X.Y for building a server-side extension or libpq-dev for building a client-side application. gyp: Call to 'pg_config --libdir' returned exit status 1. while trying to load binding.gyp gyp ERR! configure error gyp ERR! stack Error: gyp failed with exit code: 1 gyp ERR! stack at ChildProcess.onCpExit gyp/lib/configure.js:416:16) gyp ERR! stack at ChildProcess.EventEmitter.emit (events.js:99:17) gyp ERR! stack at Process._handle.onexit (child_process.js:678:10) gyp ERR! System Linux 3.2.0-39-generic gyp ERR! command "node" "/usr/local/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "rebuild" gyp ERR! cwd /home/epl/_epl_129/src/node_modules/ueberDB/node_modules/pg gyp ERR! node -v v0.8.22 gyp ERR! node-gyp -v v0.8.5 gyp ERR! not ok npm@1.2.15 node_modules/npm

ueberDB@0.1.96 node_modules/ueberDB ├── channels@0.0.2 ├── node-redis@0.1.5 ├── dirty@0.9.6 ├── async@0.1.15 ├── helenus@0.6.2 (node-uuid@1.3.3, helenus-thrift@0.7.3) ├── mysql@0.9.5 (hashish@0.0.4) └── pg@0.14.1 (deprecate@0.1.0, generic-pool@2.0.3)

nodemailer@0.3.44 node_modules/nodemailer ├── optimist@0.3.5 (wordwrap@0.0.2) ├── simplesmtp@0.2.4 (xoauth2@0.1.7, rai@0.1.7) └── mailcomposer@0.1.31 (mime@1.2.9, mimelib@0.2.12) Ensure jQuery is downloaded and up to date... Clear minfified cache... ensure custom css/js files are created... start... [2013-03-29 20:58:58.963] [INFO] console - Installed plugins: ep_etherpad-lite, ep_headings [2013-03-29 20:58:58.994] [INFO] console - Your Etherpad Lite git version is f1b60e9 [2013-03-29 20:58:58.995] [INFO] console - Report bugs at https://github.com/ether/etherpad-lite/issues [2013-03-29 20:58:59.023] [INFO] console - SSL -- enabled [2013-03-29 20:58:59.024] [INFO] console - SSL -- server key file: /etc/ssl/private/key.key [2013-03-29 20:58:59.024] [INFO] console - SSL -- Certificate Authority's certificate file: /etc/ssl/certs/key.pem [2013-03-29 20:58:59.104] [INFO] console - info - 'socket.io started' [2013-03-29 20:58:59.171] [INFO] console - You can access your Etherpad-Lite instance at http://0.0.0.0:9013/ [2013-03-29 20:58:59.171] [INFO] console - The plugin admin page is at http://0.0.0.0:9013/admin/plugins (/usr/local/lib/node_modules/npm/node_modules/node- Bildschirmfoto 2013-03-29 um 21 03 37

[2013-03-29 21:06:50.287] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:50.588] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:51.140] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:56.702] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:56.802] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:57.003] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:57.103] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:57.403] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:57.503] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:57.603] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:06:57.709] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:07:00.603] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:07:00.805] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:07:01.004] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:07:01.104] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:07:01.305] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:07:01.413] [INFO] socket.io - handshake authorized 'ldOFQRd8oxBVeSJqu1Ag' [2013-03-29 21:07:01.515] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:07:01.694] [INFO] access - [CREATE] Pad "test": Client ldOFQRd8oxBVeSJqu1Ag with IP "93.202.168.10" created the pad [2013-03-29 21:07:01.716] [INFO] ueberDB - Flushed 6 values [2013-03-29 21:07:01.916] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:07:02.016] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:07:02.116] [INFO] ueberDB - Flushed 1 values Bildschirmfoto 2013-03-29 um 21 08 46

[2013-03-29 21:09:01.743] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:09:01.843] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:09:01.943] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:09:02.043] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:09:02.143] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:09:02.243] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:09:02.303] [INFO] socket.io - handshake authorized '3jxfSPZPbJdggQDou1Ah' [2013-03-29 21:09:02.343] [INFO] ueberDB - Flushed 2 values [2013-03-29 21:09:02.559] [INFO] access - [CREATE] Pad "test": Client 3jxfSPZPbJdggQDou1Ah with IP "#.#.#.#" created the pad [2013-03-29 21:09:02.644] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:09:02.743] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:09:02.943] [INFO] ueberDB - Flushed 1 values [2013-03-29 21:09:03.043] [INFO] ueberDB - Flushed 2 values [2013-03-29 21:09:03.143] [INFO] ueberDB - Flushed 1 values

Bildschirmfoto 2013-03-29 um 21 09 08

disy-mk commented 11 years ago

@JohnMcLear will follow soon:

marcelklehr commented 11 years ago

possibly a browser issue. What does your express_sid cookie say after each of the above?

disy-mk commented 11 years ago

express_sid does not change; however this did not happen with safari...

edit: yeah, confirmed chrome thing... does not happen with FF either

JohnMcLear commented 11 years ago

So can you please clarify the exact steps to replicate? :)

marcelklehr commented 11 years ago

Chrome doesn't send the session id every time apparently, so epl generates a new session for some requests. Hence the db pollution.

disy-mk commented 11 years ago

Do we trigger the sending of the session id anywhere or does this happen automatically upon requests?

marcelklehr commented 11 years ago

that's an express functionality. we're just providing the storage mechanism.

disy-mk commented 11 years ago

I see... what about cleaning the session storage entries from db from time to time? That shouldn't be a prob for public pads, but I would need a way to validate validity of cookie (not if valid by expiry, but if valid on server side). For now I recreate sessions for group pads if 20% of their expiry already expired (I store the expiry time in a second cookie as there is no way of checking how much expiry time is left for a cookie - but that solution is not satisfying as well... -> #1526 )

disy-mk commented 11 years ago

Does this problem persist w/ 1623?

@JohnMcLear: Yes, it does

JohnMcLear commented 11 years ago

I think if you wanna fix this you are gonna have to look into the source code and figure out the cause. I'm not gonna have time to look at this for a bit

disy-mk commented 11 years ago

Already doing that but I'm a bit confused because according nodejs v0.10 doc this should work? ... must try harder....

JohnMcLear commented 11 years ago

Yea this looks like express is creating a bunch of sessions for each get request, prolly need a way to specify to create a session if one doesn't exist already.. Mheh

JohnMcLear commented 11 years ago

Btw this isn't just a Chrome bug, it's all browsers.

marcelklehr commented 11 years ago

The sessions are SET on every request in all browsers, but it doesn't create new ones for me.

disy-mk commented 11 years ago

Well, in chrome it did for me. Didnt with ff/safari

sent from my mobile

JohnMcLear commented 9 years ago

Can anyone else take this one on? I was able to replicate before but can't now ;\

DanielBickley commented 8 years ago

Hi,

I'm using the API to create users, groups, and sessions so I can more easily pipe my app's users into a secure pad. I've noticed that something similar is occuring where the sessionstorage is being set multiple times even though there is ever only one API call to create the session. You can see from my screenshot where the basic creation of a user, group, and session clutters the db with sessionstorage records. Has anybody made any headway on this apparent bug?

Thanks!

screen shot 2016-02-11 at 5 16 59 pm
JohnMcLear commented 8 years ago

I'd like to find some time/funds to take it on but as of yet haven't been able to :(

DanielBickley commented 7 years ago

I've been digging into this a bit, but with limited knowledge on the configuration specifics.

I noticed that simply using the API will trigger a db.set("sessionstorage:" + sid, sess) routine. My added db cruft is the result of using AJAX in conjunction with the API to return periodic results to my application. With my application, all session stuff is handled via the API, so in theory, according the code comments, no "sessionstorage" type db records should be kept on those requests at all.

I'm having a good bit of difficulty in tracing out exactly how the API requests are tied into all this. However, I think it still circles back to the what @JohnMcLear writes above in regards to "express is creating a bunch of sessions for each get request, prolly need a way to specify to create a session if one doesn't exist." Might I add, determine if the API is making the request, and suppressing any type of db record insert, particularily where the express_sid is not altered in this instance anyway.

Right now I'm running a nightly CRON to rip all the "sessionstorage" stuff out of my DB, but I'll try to get back to this in the coming weeks. I suppose it'll just be some trial/error stuff in terms of adjusting the socket-io express session code to look for existing session before proceeding. This is occurring in src/node/hooks/webaccess.js exports.expressConfigure(), I believe.

I'm not asking anybody to hunt/peck this out for me, but please do provide any insight if you have some ;)

Thanks!

nebulade commented 7 years ago

Since I debugged another session issue when using ep_cloudron, I came across this thread. In my case the plugin order was not always consitent causing different session behavior across restarts. Explicitly specifying the order fixed it. Luckily the order is printed when using DEBUG logging. This might not be related, but just thought it might reveal some more information also in this case, given how much plugins can do in etherpad, they might easily interfere with session as well.

JohnMcLear commented 4 years ago

Pull request in that fixes this: https://github.com/ether/etherpad-lite/pull/3793

JohnMcLear commented 4 years ago

Fixed in 3793

Loki-Afro commented 3 years ago

@JohnMcLear

do you may have any script to clean up those dead sessions? Or can provide some kinda safe way to clean them up. We are using mongodb btw. :)

JohnMcLear commented 3 years ago

Will https://github.com/ether/etherpad-lite/blob/develop/src/bin/deleteAllGroupSessions.js do it or point you in the right direction?

Loki-Afro commented 3 years ago

we are not quite sure about the internals or how to identify dead sessions - or would the script you mentioned simply solve the problem here?

JohnMcLear commented 3 years ago

IDK, run it and see? 🗡️

Backup your database first tho..