php - Laravel 11 intermittent 419 CSRF errors on login, sessions used with redis - Stack Overflow

admin管理员组

文章数量:1125444

I don't know for sure if this issue is tied to the use of redis for sessions but it seems plausible. This issue only occurs at scale with production traffic, happening on ~1-2% of login requests.

Since upgrading to laravel 11 and switching our sessions to be stored in redis (AWS Elasticache Serverless), we've been having frequent reports of 419 errors when users attempt to login. 419 means the CSRF token does not match what is stored in the session.

It appears that in this commit the regenerate method was changed to start regenerating the CSRF token in the session on login. Previously only ->migrate() was called which should not generate a new CSRF token.

The AuthenticatesUsers's trait sendLoginResponse calls this regenerate method.

I added logging to the laravel framework to try to debug the issue, the code I modified is below. Based on the logs, it appears that the CSRF token is getting generated on the load of the login page, and then regenerated when they make their POST request for login. It then compares the CSRF token sent to the token just generated with the request, which produces a mismatch.

In the example below: 16:42:08: The user lands on the login page, and a session is started which generates a CSRF token for the session which is given to the page.

16:42:13: The user posts to the login route, the regenerate method is called and a new CSRF token is generated. It can then be seen that the CSRF comparison fails because it thinks that the valid CSRF token is the one that was just generated at 16:42:13, and not the CSRF token that was generated at 16:42:08.

* * - - [31/Dec/2024:16:42:08 +0000] "GET /admin/login HTTP/1.1" 200 30400 "https://*/admin/grid/day/2024-12-29" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Safari/605.1.15"

[2024-12-31 16:42:08] .INFO: SESSION DEBUG: start: regenerateToken {"session_id":"GKkRGO4gXaHgv97SNAGwU4IBh528n6aQ3lXNMux6","csrf_token":"fzpmkW7zrN3vVIcZHwag2f4VrqZeqXwPV01Wslv8","ip_address":"*","session_cookie":null}

[2024-12-31 16:42:12] .INFO: SESSION DEBUG: regenerate: regenerateToken {"session_id":"V1tl039u7Zko2FNKnYBmnktpkpjWvYWnbinQ7p10","csrf_token":"uMGctIR0qgYT50LJSM5VRjvMeN6nRU5ZwP143uF2","ip_address":"*","session_cookie":"GKkRGO4gXaHgv97SNAGwU4IBh528n6aQ3lXNMux6"} 

* * - - [31/Dec/2024:16:42:13 +0000] "POST /admin/login HTTP/1.1" 419 67720 "https://*/admin/login" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.6 Safari/605.1.15"

[2024-12-31 16:42:13] .INFO: SESSION DEBUG: Session ID: V1tl039u7Zko2FNKnYBmnktpkpjWvYWnbinQ7p10 Hash does not match: uMGctIR0qgYT50LJSM5VRjvMeN6nRU5ZwP143uF2 vs fzpmkW7zrN3vVIcZHwag2f4VrqZeqXwPV01Wslv8  

In order to try to fix this, I overwrote the sendLoginResponse to have ->migrate() called instead of ->regenerate(), which should have restored the previous laravel behavior where a new CSRF token is not generated on login. The issue is still observed with this change, in this case it strangely appears that _token is not set on the session, even though it clearly was set merely seconds before. See note below, "token has to not be set for below code to run".

The user that attempted the below login is an employee and I confirmed they didn't have cookies disabled, which can be seen is the case anyway since the session cookie in the second request matches that of the first.

16:03:43: The user loads the site which generates a session.

16:03:47: The user attempts to login, and in this request a new session is started/a CSRF token is generated. The system thinks this is the valid session CSRF token and compares it to the CSRF token at 16:03:43, which produces a mismatch.

* * - - [07/Jan/2025:16:03:43 +0000] "GET / HTTP/1.1" 200 26101 "https://*/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36"

[2025-01-07 16:03:43] .INFO: SESSION DEBUG: start: regenerateToken {"session_id":"SSJBXTCoydtRHdDhBBH224SQBYqM5PvrGMiCRzx1","csrf_token":"jhZ6BZ2Vo5212jo4EJo6qEkF1wqHjwDHAT2zVh19","ip_address":"*","session_cookie":"SSJBXTCoydtRHdDhBBH224SQBYqM5PvrGMiCRzx1"} 

* * - - [07/Jan/2025:16:03:44 +0000] "GET /login HTTP/1.1" 200 23666 "https://*/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36"

[2025-01-07 16:03:47] .INFO: SESSION DEBUG: start: regenerateToken {"session_id":"SSJBXTCoydtRHdDhBBH224SQBYqM5PvrGMiCRzx1","csrf_token":"zvn0N1iXxY0eIvC1u6QGbQC1h3XSmxac027GVQBp","ip_address":"*","session_cookie":"SSJBXTCoydtRHdDhBBH224SQBYqM5PvrGMiCRzx1"} 

[2025-01-07 16:03:47] .INFO: SESSION DEBUG: Session ID: SSJBXTCoydtRHdDhBBH224SQBYqM5PvrGMiCRzx1 Hash does not match: zvn0N1iXxY0eIvC1u6QGbQC1h3XSmxac027GVQBp vs jhZ6BZ2Vo5212jo4EJo6qEkF1wqHjwDHAT2zVh19  

* * - - [07/Jan/2025:16:03:47 +0000] "POST /login HTTP/1.1" 419 67713 "https://*/login" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/131.0.0.0 Safari/537.36"

Code changes made for logging:

app/Http/Middleware/VerifyCsrfToken.php

namespace App\Http\Middleware;

use Illuminate\Foundation\Http\Middleware\VerifyCsrfToken as Middleware;

class VerifyCsrfToken extends Middleware
{
    protected function tokensMatch($request)
    {
        $token = $this->getTokenFromRequest($request);

        $is_session_token_string = is_string($request->session()->token());
        $is_token_string = is_string($token);
        $hash_equals = hash_equals($request->session()->token(), $token);

        if (!$is_session_token_string) {
            \Log::info('SESSION DEBUG: Session token stored in session is not a string: ' . $request->session()->token());
        }

        if (!$is_token_string) {
            \Log::info('SESSION DEBUG: Token from request is not a string: ' . $token);
        }

        if (!$hash_equals) {
            \Log::info('SESSION DEBUG: Session ID: ' . $request->session()->getId() . ' Hash does not match: ' . $request->session()->token() . ' vs ' . $token);
        }

        return $is_session_token_string && $is_token_string && $hash_equals;
    }
}

Session/Store.php:

  /**
     * Generate a new session identifier.
     *
     * @param  bool  $destroy
     * @return bool
     */
    public function regenerate($destroy = false)
    {
        return tap($this->migrate($destroy), function () {
                $this->regenerateToken();

                $ipAddress = Request::header('CF-Connecting-IP', Request::ip());
$sessionId = $this->getId();

$sessionCookieName = config('session.cookie'); // Get session cookie name from config
$sessionCookieValue = Request::cookie($sessionCookieName);

Log::info("SESSION DEBUG: regenerate: regenerateToken", [
'session_id' => $sessionId,
'csrf_token' => $this->token(),
'ip_address' => $ipAddress,
'session_cookie' => $sessionCookieValue,
]);
        });
    }

 /**
     * Start the session, reading the data from a handler.
     *
     * @return bool
     */
    public function start()
    {
        $this->loadSession();

        if (! $this->has('_token')) { // <-- _token has to not be set for below code to run
                $this->regenerateToken();

                $ipAddress = Request::header('CF-Connecting-IP', Request::ip());
$sessionId = $this->getId();

$sessionCookieName = config('session.cookie'); // Get session cookie name from config
$sessionCookieValue = Request::cookie($sessionCookieName);

Log::info("SESSION DEBUG: start: regenerateToken", [
'session_id' => $sessionId,
'csrf_token' => $this->token(),
'ip_address' => $ipAddress,
'session_cookie' => $sessionCookieValue,
]);
        }

        return $this->started = true;
    }

本文标签： phpLaravel 11 intermittent 419 CSRF errors on loginsessions used with redisStack Overflow