Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[5.0] Session Persistance Issues #8172

Closed
GrahamCampbell opened this issue Mar 26, 2015 · 178 comments
Closed

[5.0] Session Persistance Issues #8172

GrahamCampbell opened this issue Mar 26, 2015 · 178 comments
Labels

Comments

@GrahamCampbell
Copy link
Member

#6777 and #5416 still seem to be an issue, even for drivers other than file.


// cc @ammont, @esbenp, @barryvdh, @bonzai, @henrikromby, @avi123,

@ammont
Copy link

ammont commented Mar 26, 2015

We are experiencing token regenerating issue on Redis, I don't think it would be lock issue because redis is single thread and atomic, I used the method suggested in #6777 to debug and here is the log:

[2015-03-26 13:12:06] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:06] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:06] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:06] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:06] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:06] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:07] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:07] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:07] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:07] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:07] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:08] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:08] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:08] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:08] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:08] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:09] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:09] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:10] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:10] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:10] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:10] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:10] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:11] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:11] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:11] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:11] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:11] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []
[2015-03-26 13:12:11] production.INFO: ["k9OqsVTnE0QkphMjGLxfF8nnClidNXsDZo7i9H8C","9uIpGse9rdQlZJGs8NYMFH4s8KsWkvDsZ2efk5Fv","1a85f2d0adb856b874dda75f05c75ea8a7ad0c43"] [] []

you can see that the token is regenerated out of nowhere.

one more thing, when I was testing the application (sending many concurrent requests) on another tab I was not able to login!

@ammont
Copy link

ammont commented Mar 26, 2015

maybe related to this said by @avi123 in #5416:

The first issue occurs if you have multiple concurrent POSTs/PUTs, or even sequential asynchronous requests that happen in close succession such that the second request starts prior to the first request completing. The issue here is that changes to the session in the second request can be lost if the first request doesn't lock the session, but instead does a read, and then a full write at the completion of the request (I believe the method that the Session Store takes). This is the impetus for using a locking session driver in general.

@ifox
Copy link
Contributor

ifox commented Apr 7, 2015

I can confirm this is happening using the file driver as well as the memcached driver.

@ammont
Copy link

ammont commented Apr 7, 2015

Ok I added some code to log when a session starts when it stops (saves) and when the cookie is sent and here is the result:

[2015-04-07 15:11:33] local.NOTICE: CLOSED: c9dab98e17844c7127b47cfc28429fdc57ee4d9b [] []
[2015-04-07 15:11:33] local.NOTICE: COOKIE SENT: laravel_session=c9dab98e17844c7127b47cfc28429fdc57ee4d9b; expires=Tue, 07-Apr-2015 17:11:33 GMT; path=/; domain=.adview.local; httponly [] []
[2015-04-07 15:11:33] local.NOTICE: CLOSED: c9dab98e17844c7127b47cfc28429fdc57ee4d9b [] []
[2015-04-07 15:11:33] local.NOTICE: COOKIE SENT: laravel_session=c9dab98e17844c7127b47cfc28429fdc57ee4d9b; expires=Tue, 07-Apr-2015 17:11:33 GMT; path=/; domain=.adview.local; httponly [] []
[2015-04-07 15:11:33] local.INFO: session id regenerated: 3fae6afa0b40226cfba997b9ace82e73127c4791 [] []
[2015-04-07 15:11:33] local.INFO: ["EcSKhVhL8QbNMhmgrJp7nAIeXe1Z3ThuL2T8bRmx","EcSKhVhL8QbNMhmgrJp7nAIeXe1Z3ThuL2T8bRmx","c9dab98e17844c7127b47cfc28429fdc57ee4d9b"] [] []
[2015-04-07 15:11:33] local.NOTICE: CLOSED: c9dab98e17844c7127b47cfc28429fdc57ee4d9b [] []
[2015-04-07 15:11:33] local.NOTICE: COOKIE SENT: laravel_session=c9dab98e17844c7127b47cfc28429fdc57ee4d9b; expires=Tue, 07-Apr-2015 17:11:33 GMT; path=/; domain=.adview.local; httponly [] []
[2015-04-07 15:11:33] local.NOTICE: CLOSED: c9dab98e17844c7127b47cfc28429fdc57ee4d9b [] []
[2015-04-07 15:11:33] local.NOTICE: COOKIE SENT: laravel_session=c9dab98e17844c7127b47cfc28429fdc57ee4d9b; expires=Tue, 07-Apr-2015 17:11:33 GMT; path=/; domain=.adview.local; httponly [] []
[2015-04-07 15:11:33] local.NOTICE: CLOSED: 3fae6afa0b40226cfba997b9ace82e73127c4791 [] []
[2015-04-07 15:11:33] local.NOTICE: COOKIE SENT: laravel_session=3fae6afa0b40226cfba997b9ace82e73127c4791; expires=Tue, 07-Apr-2015 17:11:33 GMT; path=/; domain=.adview.local; httponly [] []
[2015-04-07 15:11:34] local.INFO: ["EcSKhVhL8QbNMhmgrJp7nAIeXe1Z3ThuL2T8bRmx","EcSKhVhL8QbNMhmgrJp7nAIeXe1Z3ThuL2T8bRmx","c9dab98e17844c7127b47cfc28429fdc57ee4d9b"] [] []
[2015-04-07 15:11:34] local.NOTICE: CLOSED: c9dab98e17844c7127b47cfc28429fdc57ee4d9b [] []
[2015-04-07 15:11:34] local.NOTICE: COOKIE SENT: laravel_session=c9dab98e17844c7127b47cfc28429fdc57ee4d9b; expires=Tue, 07-Apr-2015 17:11:34 

as you can see in the middle the session id is regenerated because I have tried logging in when sending concurrent requests, and as you can see while the session id is changed the other concurrent requests are using the prior id so on next response the cookie is rewrote and you're logged out. any idea what can make this happen?

@ifox
Copy link
Contributor

ifox commented Apr 8, 2015

After testing on multiple machines / configurations, I was able to notice that it happens only using homestead without nfs folder sync.

@laurencei
Copy link
Contributor

I tested this on Homestead (PHP 5.6.4 / Nginx 1.6.2) on my Windows 7 64bit box using VMWare. I tried using session drivers file, redis and memcache.

I could not replicate despite doing thousands of AJAX requests.

I'll keep trying some other methods...

@GrahamCampbell
Copy link
Member Author

I Taylor and I can't replicate this either, but it seems there are a good number of people that seem to have having this issue.

@LouisMT
Copy link

LouisMT commented Apr 10, 2015

Could it have something to do with a change or bug in the latest PHP version?

I'm using PHP 5.6.7 for both local development and my servers, and I have this issue on both. The rest of the setup is totally different (Windows/Debian, PHP server/nginx).

@laurencei
Copy link
Contributor

@naxiz - the issue has been known since at least Dec 2014. So it was earlier than PHP 5.6.4

But there must be some combination of PHP/Server/Laravel versions that is causing it. Or perhaps even the OS or Server.

Perhaps if more people with the issue can post their system configs/versions - we might see a common setup between them that we can use to narrow down the issue?

@laurencei
Copy link
Contributor

I've tried further on a new Forge DigitalOcean box (lowest box - 512mb ram) - running PHP 5.6.7.

I also tried with browsers Chrome41 + IE11

Still cant replicate... there must be something we are missing...

@Sladewill
Copy link

Its happening for me under xampp 3.2.1, windows 7, php 5.6, mysql 5.5.34, apache 2.4.7
As well on windows 8.1, php 5.6, mysql 5.6.24, nginx 1.7.12

@laurencei
Copy link
Contributor

@Sladewill @naxiz @ifox @ammont - what browsers are you testing with? (I know it shouldnt matter - but I'm trying to think of every possibility)

And are you using code in #6777 to do this? Or you own app? Can you try with the code in #6777 and confirm it happens using that (so we all agree on a base code to test against)

@Sladewill
Copy link

Firefox and Chrome.

@laurencei
Copy link
Contributor

@Sladewill - which exact browser versions are you using?

And what code are you running to cause this issue? If you run the code in #6777 do you get the problem?

@Sladewill
Copy link

Home Pc
Firefox 37.0.1
Chrome 41.0.2272.118 m

Work PC
Firefox Developer 39.0a2 (2015-04-06)
Chrome 41.0.2272.118 m

I'll test the code when I get home.
It happens very inconsistently with both the general Auth + Sentinel.

@LouisMT
Copy link

LouisMT commented Apr 10, 2015

My PC is running Windows 8.1, PHP 5.6.7, the PHP web server and Chrome 41.0.2272.118 m (64-bit). My first server is running Debian Sid, PHP 5.6.7 and nginx 1.6.2. My second server is running Debian Jessie, PHP 5.6.7 and nginx 1.6.2 also.

@theshiftexchange I've tried the code of issue #6777. I've run ~2500 queries without any mismatch (I checked the logs). I've also created a new Laravel 5 project and copied the added code into it, but can't reproduce it there either. Using my own Naxiz/L5-CSRF-TestCase@74d8222551cd0383c5887b108967b634c7af3b15 seconds after it, I get an exception after just 2 clicks.

@esbenp
Copy link
Contributor

esbenp commented Apr 11, 2015

The #6777 was created on my local OSX dev machine using homestead (don't remember the version though). We initially found the problem on our DigitalOcean servers created through Forge.

@ammont
Copy link

ammont commented Apr 12, 2015

@taylorotwell @GrahamCampbell I can easily replicate this error on our server and on my local machine, they have different versions of php different os, etc., I use laravel 4.1, on login form I simply click or enter the submit button 20-30 times repeatedly fast. as you know even on login the csrf token does not change, but I get a token mismatch error on this situation. can you guys try it and let me know of you get the same result?

@laurencei
Copy link
Contributor

@ammont @esbenp @naxiz @Sladewill - I've created a server to try and replicate this bug. Can you visit this server - and tell me if you can make it fail: http://45.55.164.181/

This is using the exact fork of https://github.com/Naxiz/L5-CSRF-TestCase/commit/74d8222551cd0383c5887b108967b634c7af3b15 - on a DigitalOcean server using Forge.

I still cant replicate - but I'm wondering if you can make it fail?

@jhauraw
Copy link

jhauraw commented Apr 13, 2015

We've been battling with this puzzle for 2 months now. On our busy production system, we get 2-3 TokenMismatchExceptions per 24-hr period upon a simple form submission. During this same period we have ~150 succeed without issue.

We've implemented very detailed debug logging and one pattern has emerged, which is browser related. Over the last 2 months, with 2-3 issues per-day, only these browsers have triggered the issue (by quantity, predominantly IE 11 and Android 4.4.* Chrome 41):

IE 11, Windows 8.1 - Mozilla/5.0 (Windows NT 6.3; WOW64; Trident/7.0; rv:11.0) like Gecko

WebViewer 4.0, Android 4.4.2 - Mozilla/5.0 (Linux; U; Android 4.4.2; en-us; LGLS620 Build/KOT49I.LS620ZV3) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/30.0.1599.103 Mobile Safari/537.36

Chrome 41, Android 4.4.4 - Mozilla/5.0 (Linux; Android 4.4.4; SAMSUNG-SM-G870A Build/KTU84P) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.96 Mobile Safari/537.36

Chrome 41, Android 4.4.2 - Mozilla/5.0 (Linux; Android 4.4.2; SCH-I545 Build/KOT49H) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.2272.96 Mobile Safari/537.36

Safari 8.0, IOS 8.2 - Mozilla/5.0 (iPhone; CPU iPhone OS 8_2 like Mac OS X) AppleWebKit/600.1.4 (KHTML, like Gecko) Version/8.0 Mobile/12D508 Safari/600.1.4

Related SO question:
http://stackoverflow.com/questions/29380806/tokenmismatch-only-certain-browsers-laravel-5-fresh-production

We have a Forge managed Linode with LEMP (nginx 1.6.2, php 5.6.6-1+deb.sury.org~trusty+1 and Laravel 5 up-to-date, File Session driver).

So far, we have been unable to replicate in our testing on the said browsers.

Here's recent log chain of events, for a user on IE 10:

// ORIGINAL SESSION STARTED
Apr 12 13:37:23 Session {"start":1428871043,"id":"bd5181ecfada5504c7f1b07522b3c25f94ca7a0f","token":"dh7iw7CR3rlXcvLd51zSQH79PWgAkH2fyOs6cKBl","ip":"173.79.XX.XXX","method":"GET","url":"https://sub.domain.com/place/name","ua":"Mozilla/5.0 (compatible; MSIE 10.0; Windows NT 6.2; WOW64; Trident/6.0)"} []

// FORM SUBMITTED 2.5 minutes later.
Apr 12 13:41:00 SESSION ID: 461bb378850caac38bd8881979e866dddf608113 [] []
Apr 12 13:41:00 SESSION token: Df0vWqhKHbzIdt4nwbhse5htywhMRUkyPl7p0lRs [] []
Apr 12 13:41:00 REQUEST INPUT _token: dh7iw7CR3rlXcvLd51zSQH79PWgAkH2fyOs6cKBl [] []
Apr 12 13:41:00 REQUEST HEADER X-CSRF-TOKEN:  [] []
Apr 12 13:41:00 REQUEST HEADER X-XSRF-TOKEN:  [] []
Apr 12 13:41:00 REQUEST URL: https://sub.domain.com/requests/post [] []

// RAW REQUEST
Apr 12 13:41:00 array (   'USER' => 'forge',   'HOME' => '/home/forge',   'FCGI_ROLE' => 'RESPONDER',   'APP_ENV' => 'production',   'QUERY_STRING' => '',   'REQUEST_METHOD' => 'POST',   'CONTENT_TYPE' => 'application/x-www-form-urlencoded',   'CONTENT_LENGTH' => '275',   'SCRIPT_FILENAME' => '/home/forge/domain.com/public/index.php',   'SCRIPT_NAME' => '/index.php',   'REQUEST_URI' => '/requests/post',   'DOCUMENT_URI' => '/index.php',   'DOCUMENT_ROOT' => '/home/forge/domain.com/public',   'SERVER_PROTOCOL' => 'HTTP/1.1',   'GATEWAY_INTERFACE' => 'CGI/1.1',   'SERVER_SOFTWARE' => 'nginx/1.6.2',   'REMOTE_ADDR' => '173.79.XX.XXX',   'REMOTE_PORT' => '62854',   'SERVER_ADDR' => '104.237.XX.XXX',   'SERVER_PORT' => '443',   'SERVER_NAME' => 'domain.com',   'HTTPS' => 'on',   'REDIRECT_STATUS' => '200',   'HTTP_ACCEPT' => 'text/html, application/xhtml+xml, */*',   'HTTP_REFERER' => 'https://sub.domain.com/place/name?t=%2Bkeyword',   'HTTP_ACCEPT_LANGUAGE' => 'en-US',   'HTTP_USER_AGENT' => 'Mozilla/5.0 (compatible; MSIE 10.0; Windows NT 6.2; WOW64; Trident/6.0)',   'HTTP_CONTENT_TYPE' => 'application/x-www-form-urlencoded',   'HTTP_ACCEPT_ENCODING' => 'gzip, deflate',   'HTTP_HOST' => 'sub.domain.com',   'HTTP_CONTENT_LENGTH' => '275',   'HTTP_DNT' => '1',   'HTTP_CONNECTION' => 'Keep-Alive',   'HTTP_CACHE_CONTROL' => 'no-cache',   'HTTP_COOKIE' => '_ga=GA1.2.1070026939.1428881850; _gat=1',   'PHP_SELF' => '/index.php',   'REQUEST_TIME_FLOAT' => 1428871260.0079651,   'REQUEST_TIME' => 1428871260, ) [] []

Apr 12 13:41:00 REQUEST PATH: requests/post [] []
Apr 12 13:41:00 SERVER: array (   '_ga' => NULL,   '_gat' => NULL, ) [] []
Apr 12 13:41:00 COOKIE: array (   '_token' => 'Df0vWqhKHbzIdt4nwbhse5htywhMRUkyPl7p0lRs', ) [] []

Apr 12 13:41:00 TokenMismatchExpection thrown

Apr 12 13:41:00 ExceptionHandler@render: TokenMismatchException: Redirecting back. {"previous":null} []

// 2nd SESSION STARTED
Apr 12 13:41:00 Session {"start":1428871260,"id":"f408a809ca246322928880a47509a8d0b455e519","token":"aPWGA6oOn13oayiVez0VhGuG2SYajD6wkr7wFfMy","ip":"173.79.XX.XXX","method":"GET","url":"https://sub.domain.com/place/name","ua":"Mozilla/5.0 (compatible; MSIE 10.0; Windows NT 6.2; WOW64; Trident/6.0)"} []

@laurencei
Copy link
Contributor

Ping @ammont @esbenp @naxiz @Sladewill.

Can you please see if you have the problem on this server: http://45.55.164.181/

I cant replicate - but I'm wondering if you can? Might help pinpoint the issue.

@Sladewill
Copy link

As far as I can see on that server specifically the issue doesn't seem to occur. But another issue that could be related is the fact the laravel session cookie seems to expire randomly, when it does a new session gets created like when you logout so you would lose that token?

@ammont
Copy link

ammont commented Apr 27, 2015

@taylorotwell @GrahamCampbell @theshiftexchange @esbenp @naxiz @Sladewill
After a lot of investigation on the issue in our company, I came to this result, I hope it helps, first of all here is our environment specifications:

PHP: 5.3.3
LARAVEL: 4.1
OS: centos 6 on server and os x mavericks in development environment
APACHE: 2
MYSQL: 5.6.19
REDIS: 2.4.10
PREDIS: 0.8.*

First of all it seems that the TokenMistmatch exception occurs in a varied different conditions, I nearly investigated all of them and was able to solve some of them, some depends on the logic behind the session and some can be bugs. In the following i will explain each situation that I have faced.

1. Expired sessions
Let's say you have configured your session for 3 hours a user opens up a form and for some reason he leaves the computer (getting a cup of coffee) so after 3 hours when the session is expired he tries to submit a form and gets a token exception. this is why everyone once in while gets a token errror regardless of how much stable the application is, I can imagine of 2 ways to prevent it and they're renewing the session cookie using ajax on a timely basis, or increasing the session expire time to a considerable amount of time.

2. Concurrent requests when session is expired
Sometimes on the load of your first page concurrent requests happen, for example the user has two different tabs open on chrome and when he reopens chrome chrome sends the requests simultaneously or you may have multiple concurrent ajax request on the load of the first page of your application. so note that the session cookie is received after the first response is received but you may send the next request before this happens and therefore you will get a new session (new cookie) on each requests, this can lead to token exception if one of these requests populates a form. you can prevent this scenario based on it's source, for example if the ajax request are causing the problem and you do not use session in ajax responses, you can disable sending the session cookie if the request is ajax, in the second scenario (clicking the submit button multiple times) you can simple disable the button once it's submitted.

3. Concurrent requests on login
When login is occurred, laravel for security reasons changes the session id, copy the session data and DESTROYS THE LAST SESSION so let say for some reason when logging in concurrent requests happen (clicking the login button multiple times) so the session id would be regenerated multiple times and DESTROYS the last generated sessions in the server side, as some of these requests still use the prior session id (which does not exist in the server side anymore) it leads to regenerating the CSRF token, please note that normally laravel does not regenerate the token on login if it can find the token in guest (not logged in) session, but in this case as the guest session is destroyed as a result it will regenerate the token and it can result to token exception in other requests that are using the original token. also note that not only this issue can result in token exception it can also result in the user being logged out after one request, because the concurrent requests can change the logged in session. I solved this issue by changing one line in the laravel code, in Illuminate\Auth\Guard:updateSession:

protected function updateSession($id)
{
    $this->session->put($this->getName(), $id);

    //$this->session->migrate(true);
    $this->session->migrate()
}

passing true to the migrate method of the session store will result in destroying the session on the server after migration, so now the data will remain on the server and destroyed on their expire time rather than on this request and it will solve the issue. I don’t know if we can call this a bug in laravel, but I guess we can come up with a better solution for this.

4. Browsers
After investigating the logs it turned out that some of these token exceptions were because of the user’s browser not accepting the session cookie,I saw it the most on iOS Safari, I believe this is something we can do nothing about it.

5. Redis bug
Some of the token exceptions on our sever was because of redis, for some reason laravel could not read the session data from the redis server when opening the session so it would result to the regeneration of the CSRF token. it was happening randomly on our server, so I tried changing the session driver and this type of exceptions faded away. I tried database, apc and file drivers and none produced this issue. I have not yet found what is causing the bug but i think it can be a bug with redis or the predis library. (as you know laravel 4.1 is not using the latest version of predis because of compatibility issues).

Okay these are my experiences of the last 2 month working on this issue. I hope it may change your point of view regarding solution to this issue, the most important thing is that the token exception does not happen because of one reason it’s can be a result of multiple issue. please share with me if you have had similar incident or you have something new.

@GrahamCampbell
Copy link
Member Author

LARAVEL: 4.1

We're not interested in issues with 4.1.

PHP: 5.3.3

We're not interested with issues with PHP 5.3.

@GrahamCampbell
Copy link
Member Author

We want replication on Laravel 5.x.

@GrahamCampbell
Copy link
Member Author

We're not interested in issues with 4.1.

This is because it doesn't pose a security issue so we have no intention to patch it on 4.1.x.

@diegofelix
Copy link
Contributor

I have the same problem and here is how i'm tested and fixed the problem.

First, i knew i have some 404 ajax and resources ( javascripts ) on my site. So I logged on the site, and put four tabs opened with my site in firefox.

The Firefox has a nice tool called "Reload all tabs". So I did it and with a few refresh all tabs I get logout.

Then, I removed all 404 requests and tried again, and, after 20 attempts, no logouts from now.

@OskarD
Copy link
Contributor

OskarD commented Jun 22, 2015

@Kuijkens I don't know why it works sometimes, but when I get 'the error' it's because the form is sending a different (Seemingly random) token than what is stored in the session. Are you sure this is not the same issue?

@sameerpanjwani
Copy link

@Kuijkens so it's expected behaviour for session and token to get refreshed after a 404? Any reason for that being necessary or that just the way it's made?

And some times a 404 is triggered even on valid routes? That's what seems to happen in my environment randomly...it's actually first a "Whoops something went wrong...notfoundexception" followed by tokenmismatch...on fast ajax requests...and hence guessed that this could be issue others are facing..and just wanted a way to ensure that even if 404 did come about, the token does not get refreshed...is there any way to ensure that it doesn't get refreshed on 404 then my problem will be solved at least ;) because I can't figure why I get a notfound sometimes on valid routes, it's rare but happens and then it results in this tokenmismatch....

@levacic
Copy link
Contributor

levacic commented Jun 22, 2015

@Kuijkens

@diegofelix @sameerpanjwani Obviously 404 response will return a tokenmismatch exception afterwards to other requests or calls! If you got 1 error somewhere, your application will die and therefore refresh your session. All other requests will then return a tokenmismatch exception.

What? Why would your session get refreshed after a 404? This is not true, and I've just confirmed in a clean install.

Also, that would be a horrible user experience, because users would basically be logged out after visiting a missing page.

@Kuijkens
Copy link

@levacic Sorry my bad, was getting frustrated about everybody just commenting their issues in here. Of-course a 4xx will not refresh your session.

I do not have any reponses other then 200, I do not have concurrent and high frequency ajax calls. No exceptions are being thrown (we log everything on bugsnag). Still once in a while, about 0,1%, a request is returning a tokenmismatch caused by a regeneration of the session (i've actually logged this), not caused by session expiring or any thing like this. We have this problem both on Redis and Memcache. This is actually influencing the user experience on our website!

Since this is only happening on our production environment (we can not reproduce the problem on develop or staging). I had to exclude all vital ajax routes from CSRF verification. Since nobody is interested in our bugsnag report or logs it kinda feels like nobody is working on this issue and people are only cluttering this thread with non related issues. This problem is actually costing us users and thus money and is kind of unacceptable. (it is the only laravel issue we are having btw, everything else works like a charm and is awesome!)

@laurencei
Copy link
Contributor

@Kuijkens - what exactly is your production environment config? i.e .server, os, php version etc?

@Kuijkens
Copy link

@theshiftexchange

Environment: AWS Beanstalk (64bit Amazon Linux 2015.03 v1.4.1 running PHP 5.6)
PHP 5.6.8
Apache 2.4.12
Latest Laravel 5.0.x
Website: www.studocu.com

Weird thing is we have a replica of this setup for staging and we can not reproduce it there as well. I guess with just 7 dev's working on staging we do not have enough ajax calls to get a single error. On production though we hundreds of users online at the same second.

@laurencei
Copy link
Contributor

@Kuijkens - so here is an idea; Can you 'duplicate' that AWS environment? Put a copy of your app on it - and confirm the bug still occurs?

Then - if you are trusting enough - could you give @taylorotwell access and the steps to reproduce (if he is open to the idea - I'm just putting it out there).

The biggest issue is the difficulty in replicating the issue. So far we've not been able to get access to an environment where we can duplicate it. I've tried on different cloud providers - and I cant seem to get it to trigger...

@Kuijkens
Copy link

@theshiftexchange - I willing to give it a go, but I don't think it will work. Our staging environment is a duplicate of our production. Like I said before, we can not reproduce the bug ourselves (on both production or staging). The only thing that makes this bug visible is a high user volume website and Bugsnag. I'm guessing more applications suffer from this but they don't even know it. It is only happening about once or twice per hour (random calls, random routes, random users) versus thousands of successful requests.

@laurencei
Copy link
Contributor

Can you try hitting your staging site with a load tester - like https://www.blitz.io/ - can that trigger it?

@Kuijkens
Copy link

@theshiftexchange I doubt that, all our ajax requests are user induced. I should build in a custom ajax request then, which basically does nothing but will load on various times.

@red55der
Copy link

Same problem here. Randomly. TokenMismatchException line 46. Happens with IE Win8.1 or IOS.
Can't reproduce it.
Simple form application (html+bootstrap+jqueryui) with default Laravel auth
Session store in database
Laravel 5.1
PHP 5.5.9
Apache 2.4
Cleared cache etc

Session cookie gets reinit every request. Sow GET login page has other session then POST login page.

@dakira
Copy link
Contributor

dakira commented Jun 22, 2015

For me this problem went away when I updated my Homestead machine image from 0.2.6 to 0.2.7, destroyed my machine and recreated it.

@ghost
Copy link

ghost commented Jun 22, 2015

I solved my problem putting session_start() in the top of my routes file.

El 22/6/2015, a las 19:41, red55der notifications@github.com escribió:

Same problem here. Randomly. TokenMismatchException line 46. Happens with IE Win8.1 or IOS.
Can't reproduce it.
Simple form application (html+bootstrap+jqueryui) with default Laravel auth
Session store in database
Laravel 5.1
PHP 5.5.9
Apache 2.4
Cleared cache etc

Session cookie gets reinit every request. Sow GET login page has other session then POST login page.


Reply to this email directly or view it on GitHub #8172 (comment).

@levacic
Copy link
Contributor

levacic commented Jun 23, 2015

@Kuijkens I understand your frustration, just wanted to correct the wrong info, as it will only further confuse users reading this thread. I'm subscribed to the issue for the same reason as you - random token mismatch exceptions that cannot be reliably reproduced, though in a Laravel 4.2 app. I'm not posting extra info about my situation since it was mentioned that this issue is specifically concerned with Laravel 5, but I'm watching in case someone figures out the problem, because there's a good chance that the root cause might be similar.

@GrahamCampbell
Copy link
Member Author

session_start() in the top of my routes file.

Oh wow. NEVER do that!

@ghost
Copy link

ghost commented Jun 23, 2015

why? That solved my problem

@GrahamCampbell
Copy link
Member Author

Because that's totally incorrect.

@GrahamCampbell
Copy link
Member Author

Closing this as zero progress is being made.

@ghost
Copy link

ghost commented Jun 23, 2015

Yes, I know but my desperation is enough

@dakira
Copy link
Contributor

dakira commented Jun 23, 2015

@GrahamCampbell most people seem to experience this with Homestead. Whatever the issue is, updating homestead solved it on all my machines.

BTW: I could re-produce this with the most simple imaginable app that subits a form (no ajax).

@red55der
Copy link

I log the Exception header which show that de TokenMismatch mainly occurs on IE Win8.1 or IOS Safari.

I can reproduce it in IE11 when i set the Privacy on High.

solution that works here:
add a customheader in the middleware stack by create a file P3PHeader in App\Http\Middleware;

<?php namespace App\Http\Middleware;

use Closure;

class P3PHeader
{
    public function handle($request, Closure $next)
    {
        $response = $next($request);
        $response->headers->set('P3P', 'CP="IDC DSP COR ADM DEVi TAIi PSA PSD IVAi IVDi CONi HIS"');
        return $response;
    }
}

And added 'App\Http\Middleware\P3PHeader' to $middleware in Kernel.php

@tuurbo
Copy link
Contributor

tuurbo commented Jun 26, 2015

The issue with multiple rapid ajax calls causing token errors and such only seems to be an issue on my local machine and after running artisan optimize --force i no longer see the issue

@Kuijkens
Copy link

@red55der This is looking very promising! For the first time I'm able to reproduce the error myself. Adding the headers like you suggested solved it for me, at least locally. I'm going to hotfix deploy this right away to production and monitor it for a couple of hours. Will be back with the results asap.

@mga242
Copy link

mga242 commented Jun 26, 2015

@red55der Make sure you exclude responses that are redirects, otherwise it will throw an error: http://stackoverflow.com/questions/30490821/laravel-5-tokenmismatchexception-on-php-5-6-9

@Kuijkens
Copy link

@red55der @tuurbo Tried both suggestions, random session regenerations still occurs.

We are going to upgrade to L5.1 really soon, hopefully things will magically sort itself out.

@tuurbo
Copy link
Contributor

tuurbo commented Jun 29, 2015

@Kuijkens Do you use apache on your local machine? I run windows 8.1 and just switched to nginx and that also solved the issue for me, just like artisan optimize --force did while using apache.

@laravel laravel locked and limited conversation to collaborators Jun 29, 2015
@GrahamCampbell
Copy link
Member Author

Please continue this on the forums.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests