From 85556d9c4c228c5b79dd3d850ddbd047551f84f5 Mon Sep 17 00:00:00 2001 From: the-djmaze <> Date: Wed, 30 Nov 2022 09:00:28 +0100 Subject: [PATCH] Add more logging to find solution for #719 --- .../libraries/RainLoop/Actions/UserAuth.php | 56 ++++++++----------- .../v/0.0.0/app/libraries/RainLoop/Utils.php | 11 +++- .../0.0.0/app/libraries/snappymail/crypt.php | 12 ++-- 3 files changed, 37 insertions(+), 42 deletions(-) diff --git a/snappymail/v/0.0.0/app/libraries/RainLoop/Actions/UserAuth.php b/snappymail/v/0.0.0/app/libraries/RainLoop/Actions/UserAuth.php index 6c7b858a4..cd2937b22 100644 --- a/snappymail/v/0.0.0/app/libraries/RainLoop/Actions/UserAuth.php +++ b/snappymail/v/0.0.0/app/libraries/RainLoop/Actions/UserAuth.php @@ -334,11 +334,9 @@ trait UserAuth private function SetSignMeToken(MainAccount $oAccount): void { - $this->ClearSignMeData(); - +// $this->ClearSignMeData(); $uuid = \SnappyMail\UUID::generate(); $data = \SnappyMail\Crypt::Encrypt($oAccount); - Utils::SetCookie( self::AUTH_SIGN_ME_TOKEN_KEY, \SnappyMail\Crypt::EncryptUrlSafe([ @@ -348,13 +346,7 @@ trait UserAuth ]), \time() + 3600 * 24 * 30 // 30 days ); - - $this->StorageProvider()->Put( - $oAccount, - StorageType::SIGN_ME, - $uuid, - $data[2] - ); + $this->StorageProvider()->Put($oAccount, StorageType::SIGN_ME, $uuid, $data[2]); } public function GetAccountFromSignMeToken(): ?MainAccount @@ -368,36 +360,32 @@ trait UserAuth StorageType::SIGN_ME, $aTokenData['u'] ); - if ($sAuthToken) { - $aAccountHash = \SnappyMail\Crypt::Decrypt([ - \array_key_last($aTokenData), - \base64_decode(\end($aTokenData)), - $sAuthToken - ]); - if (\is_array($aAccountHash)) { - $oAccount = MainAccount::NewInstanceFromTokenArray($this, $aAccountHash); - if ($oAccount) { - $this->CheckMailConnection($oAccount); - // Update lifetime - $this->SetSignMeToken($oAccount); - return $oAccount; - } - \SnappyMail\Log::notice(self::AUTH_SIGN_ME_TOKEN_KEY, 'has no account'); - } else { - \SnappyMail\Log::notice(self::AUTH_SIGN_ME_TOKEN_KEY, 'decrypt failed'); - } - } else { - \SnappyMail\Log::notice(self::AUTH_SIGN_ME_TOKEN_KEY, "server token not found for {$aTokenData['e']}/.sign_me/{$aTokenData['u']}"); + if (!$sAuthToken) { + throw new \RuntimeException("server token not found for {$aTokenData['e']}/.sign_me/{$aTokenData['u']}"); } + $aAccountHash = \SnappyMail\Crypt::Decrypt([ + \array_key_last($aTokenData), + \base64_decode(\end($aTokenData)), + $sAuthToken + ]); + if (!\is_array($aAccountHash)) { + throw new \RuntimeException('token decrypt failed'); + } + $oAccount = MainAccount::NewInstanceFromTokenArray($this, $aAccountHash); + if (!$oAccount) { + throw new \RuntimeException('token has no account'); + } + $this->CheckMailConnection($oAccount); + // Update lifetime + $this->SetSignMeToken($oAccount); + return $oAccount; } catch (\Throwable $oException) { - \SnappyMail\Log::notice(self::AUTH_SIGN_ME_TOKEN_KEY, $oException->getMessage()); + \SnappyMail\Log::warning(self::AUTH_SIGN_ME_TOKEN_KEY, $oException->getMessage()); } + $this->ClearSignMeData(); } - - $this->ClearSignMeData(); - return null; } diff --git a/snappymail/v/0.0.0/app/libraries/RainLoop/Utils.php b/snappymail/v/0.0.0/app/libraries/RainLoop/Utils.php index c8c58a635..3492cfb0e 100644 --- a/snappymail/v/0.0.0/app/libraries/RainLoop/Utils.php +++ b/snappymail/v/0.0.0/app/libraries/RainLoop/Utils.php @@ -195,12 +195,17 @@ class Utils */ // Set the new 4K split cookie foreach (\str_split($sValue, $iMaxSize) as $i => $sPart) { + \SnappyMail\Log::debug('COOKIE', "set {$sName}~{$i}"); static::_SetCookie($i ? "{$sName}~{$i}" : $sName, $sPart, $iExpire); } // Delete unused old 4K split cookie parts - while (($sCookieName = "{$sName}~" . ++$i) && isset($_COOKIE[$sCookieName])) { - unset($_COOKIE[$sCookieName]); - static::_SetCookie($sCookieName, '', \time() - 3600 * 24 * 30); + foreach (\array_keys($_COOKIE) as $sCookieName) { + $aSplit = \explode('~', $sCookieName); + if (isset($aSplit[1]) && $aSplit[0] == $sName && $aSplit[1] > $i) { + \SnappyMail\Log::debug('COOKIE', "unset {$sCookieName}"); + unset($_COOKIE[$sCookieName]); + static::_SetCookie($sCookieName, '', \time() - 3600 * 24 * 30); + } } } diff --git a/snappymail/v/0.0.0/app/libraries/snappymail/crypt.php b/snappymail/v/0.0.0/app/libraries/snappymail/crypt.php index 6ec79cec0..12f221d6a 100644 --- a/snappymail/v/0.0.0/app/libraries/snappymail/crypt.php +++ b/snappymail/v/0.0.0/app/libraries/snappymail/crypt.php @@ -65,11 +65,11 @@ abstract class Crypt } } } catch (\Throwable $e) { - \trigger_error(__CLASS__ . "::{$fn}(): " . $e->getMessage()); + Log::error('Crypt', "{$fn}(): {$e->getMessage()}"); } -// \trigger_error(__CLASS__ . '::Decrypt() invalid $data or $key'); + Log::warning('Crypt', 'Decrypt() invalid $data or $key'); } else { -// \trigger_error(__CLASS__ . '::Decrypt() invalid $data'); + Log::warning('Crypt', 'Decrypt() invalid $data'); } } @@ -77,7 +77,7 @@ abstract class Crypt { $data = static::jsonDecode($data); if (!\is_array($data)) { -// \trigger_error(__CLASS__ . '::DecryptFromJSON() invalid $data'); + Log::notice('Crypt', 'DecryptFromJSON() invalid $data'); return null; } return static::Decrypt(\array_map('base64_decode', $data), $key); @@ -87,7 +87,7 @@ abstract class Crypt { $data = \explode('.', $data); if (!\is_array($data)) { -// \trigger_error(__CLASS__ . '::DecryptUrlSafe() invalid $data'); + Log::notice('Crypt', 'DecryptUrlSafe() invalid $data'); return null; } return static::Decrypt(\array_map('MailSo\\Base\\Utils::UrlSafeBase64Decode', $data), $key); @@ -175,6 +175,7 @@ abstract class Crypt if (!static::$cipher) { throw new \Exception('openssl $cipher not set'); } + Log::debug('Crypt', 'openssl_decrypt() with cipher ' . static::$cipher); return \openssl_decrypt( $data, static::$cipher, @@ -195,6 +196,7 @@ abstract class Crypt if (!static::$cipher) { throw new \Exception('openssl $cipher not set'); } + Log::debug('Crypt', 'openssl_encrypt() with cipher ' . static::$cipher); $result = \openssl_encrypt( $data, static::$cipher,