diff --git a/lib/private/Authentication/Token/DefaultTokenProvider.php b/lib/private/Authentication/Token/DefaultTokenProvider.php index 5167b4a8d404..81ef2a25df24 100644 --- a/lib/private/Authentication/Token/DefaultTokenProvider.php +++ b/lib/private/Authentication/Token/DefaultTokenProvider.php @@ -75,6 +75,18 @@ public function __construct(DefaultTokenMapper $mapper, ICrypto $crypto, IConfig * @return IToken */ public function generateToken($token, $uid, $loginName, $password, $name, $type = IToken::TEMPORARY_TOKEN) { + $this->logger->debug('generating token {token}, uid {uid}, loginName {loginName}, pwd {pwd}, name {name}, type {type}', + [ + 'app' => __METHOD__, + 'token' => $this->hashToken($token), + 'uid' => $uid, + 'loginName' => $loginName, + 'pwd' => $password !== null ? 'set' : 'empty', + 'name' => $name, + 'type' => $type === IToken::TEMPORARY_TOKEN ? 'temporary' : 'permanent' + ] + ); + $this->logger->logException(new \Exception(), ['app' => __METHOD__]); $dbToken = new DefaultToken(); $dbToken->setUid($uid); $dbToken->setLoginName($loginName); @@ -101,6 +113,10 @@ public function updateToken(IToken $token) { if (!($token instanceof DefaultToken)) { throw new InvalidTokenException(); } + $this->logger->debug( + 'updating token {tokenId}, last check is now {now}', + ['app' => __METHOD__, 'tokenId' => $token->getId(), 'now' => $token->getLastCheck()] + ); $this->mapper->update($token); } @@ -119,6 +135,10 @@ public function updateTokenActivity(IToken $token) { if ($token->getLastActivity() < ($now - 60)) { // Update token only once per minute $token->setLastActivity($now); + $this->logger->debug( + 'updating activity of token {tokenId} to {now}', + ['app' => __METHOD__, 'tokenId' => $token->getId(), 'now' => $now] + ); $this->mapper->update($token); } } @@ -147,6 +167,10 @@ public function getToken($tokenId) { try { return $this->mapper->getToken($this->hashToken($tokenId)); } catch (DoesNotExistException $ex) { + $this->logger->debug( + 'token {token} does not exist', + ['app'=>__METHOD__, 'token' => $this->hashToken($tokenId) ] + ); throw new InvalidTokenException(); } } @@ -189,6 +213,10 @@ public function setPassword(IToken $token, $tokenId, $password) { * @param string $token */ public function invalidateToken($token) { + $this->logger->debug( + 'invalidating token {token}', + ['app' => __METHOD__, 'token' => $this->hashToken($token)] + ); $this->mapper->invalidate($this->hashToken($token)); } @@ -199,6 +227,10 @@ public function invalidateToken($token) { * @param int $id */ public function invalidateTokenById(IUser $user, $id) { + $this->logger->debug( + 'invalidating token for uid {uid} by id {token}', + ['app' => __METHOD__, 'uid' => $user->getUID(), 'id' => $id] + ); $this->mapper->deleteById($user, $id); } @@ -206,6 +238,10 @@ public function invalidateTokenById(IUser $user, $id) { * Invalidate (delete) old session tokens */ public function invalidateOldTokens() { + $this->logger->debug( + 'invalidating old tokens', + ['app' => __METHOD__] + ); $olderThan = $this->time->getTime() - (int) $this->config->getSystemValue('session_lifetime', 60 * 60 * 24); $this->logger->info('Invalidating tokens older than ' . date('c', $olderThan), ['app' => 'cron']); $this->mapper->invalidateOld($olderThan); diff --git a/lib/private/User/Session.php b/lib/private/User/Session.php index 678b769ef5ff..c59aa6f0f098 100644 --- a/lib/private/User/Session.php +++ b/lib/private/User/Session.php @@ -32,6 +32,7 @@ namespace OC\User; +use Doctrine\DBAL\Exception\UniqueConstraintViolationException; use Exception; use OC; use OC\Authentication\Exceptions\InvalidTokenException; @@ -249,6 +250,7 @@ public function validateSession() { try { $token = $this->session->getId(); } catch (SessionNotAvailableException $ex) { + $this->logger->logException($ex, ['app' => __METHOD__]); return; } } else { @@ -316,6 +318,14 @@ public function getLoginName() { * @throws LoginException */ public function login($uid, $password) { + $this->logger->debug( + 'regenerating session id for uid {uid}, password {password}', + [ + 'app' => __METHOD__, + 'uid' => $uid, + 'password' => empty($password) ? 'empty' : 'set' + ] + ); $this->session->regenerateId(); if ($this->validateToken($password, $uid)) { @@ -349,7 +359,7 @@ public function logClientIn($user, $password, IRequest $request) { if (!$isTokenPassword && $this->isTwoFactorEnforced($user)) { throw new PasswordLoginForbiddenException(); } - if (!$this->login($user, $password) ) { + if (!$this->login($user, $password)) { $users = $this->manager->getByEmail($user); if (count($users) === 1) { return $this->login($users[0]->getUID(), $password); @@ -359,7 +369,7 @@ public function logClientIn($user, $password, IRequest $request) { if ($isTokenPassword) { $this->session->set('app_password', $password); - } else if($this->supportsCookies($request)) { + } else if ($this->supportsCookies($request)) { // Password login, but cookies supported -> create (browser) session token $this->createSessionToken($request, $this->getUser()->getUID(), $user, $password); } @@ -446,7 +456,7 @@ public function prepareUserLogin($firstTimeLogin = false) { $this->logger->warning( 'Skeleton not created due to missing read permission in skeleton directory' ); - } catch(\OC\HintException $hintEx) { + } catch (\OC\HintException $hintEx) { // only if Skeleton no existing Dir $this->logger->error($hintEx->getMessage()); } @@ -472,6 +482,7 @@ public function tryBasicAuthLogin(IRequest $request) { * necessary but the iOS App reads cookies from anywhere instead * only the DAV endpoint. * This makes sure that the cookies will be valid for the whole scope + * * @see https://github.com/owncloud/core/issues/22893 */ $this->session->set( @@ -628,12 +639,19 @@ public function loginWithApache(IApacheBackend $apacheBackend) { if ($this->getUser() !== null && $uid === $this->getUser()->getUID()) { return true; // nothing to do } + $this->logger->debug( + 'regenerating session id for uid {uid}', + [ + 'app' => __METHOD__, + 'uid' => $uid + ] + ); $this->session->regenerateId(); $this->manager->emit('\OC\User', 'preLogin', [$uid, '']); // Die here if not valid - if(!$apacheBackend->isSessionActive()) { + if (!$apacheBackend->isSessionActive()) { return false; } @@ -701,7 +719,17 @@ public function createSessionToken(IRequest $request, $uid, $loginName, $passwor } catch (SessionNotAvailableException $ex) { // This can happen with OCC, where a memory session is used // if a memory session is used, we shouldn't create a session token anyway + $this->logger->logException($ex, ['app' => __METHOD__]); return false; + } catch (UniqueConstraintViolationException $ex) { + $this->logger->error( + 'There are code paths that trigger the generation of an auth ' . + 'token for the same session twice. We log this to trace the code ' . + 'paths. Please send all log lines belonging to this request id.', + ['app' => __METHOD__] + ); + $this->logger->logException($ex, ['app' => __METHOD__]); + return true; // the session already has an auth token, go ahead. } } @@ -747,16 +775,39 @@ private function checkTokenCredentials(IToken $dbToken, $token) { // Checked performed recently, nothing to do now return true; } + $this->logger->debug( + 'checking credentials for token {token} with token id {tokenId}, last check at {lastCheck} was more than {last_check_timeout} min ago', + [ + 'app' => __METHOD__, + 'token' => $this->hashToken($token), + 'tokenId' => $dbToken->getId(), + 'lastCheck' => $lastCheck, + 'last_check_timeout' => $last_check_timeout + ] + ); try { $pwd = $this->tokenProvider->getPassword($dbToken, $token); } catch (InvalidTokenException $ex) { - // An invalid token password was used -> log user out + $this->logger->error( + 'An invalid token password was used for token {token} with token id {tokenId}', + ['app' => __METHOD__, 'token' => $this->hashToken($token), 'tokenId' => $dbToken->getId()] + ); + $this->logger->logException($ex, ['app' => __METHOD__]); return false; } catch (PasswordlessTokenException $ex) { // Token has no password if (!is_null($this->activeUser) && !$this->activeUser->isEnabled()) { + $this->logger->debug( + 'user {uid}, {email}, {displayName} was disabled', + [ + 'app' => __METHOD__, + 'uid' => $this->activeUser->getUID(), + 'email' => $this->activeUser->getEMailAddress(), + 'displayName' => $this->activeUser->getDisplayName(), + ] + ); $this->tokenProvider->invalidateToken($token); return false; } @@ -768,6 +819,15 @@ private function checkTokenCredentials(IToken $dbToken, $token) { if ($this->manager->checkPassword($dbToken->getLoginName(), $pwd) === false || (!is_null($this->activeUser) && !$this->activeUser->isEnabled())) { + $this->logger->debug( + 'user uid {uid}, email {email}, displayName {displayName} was disabled or password changed', + [ + 'app' => __METHOD__, + 'uid' => $this->activeUser->getUID(), + 'email' => $this->activeUser->getEMailAddress(), + 'displayName' => $this->activeUser->getDisplayName(), + ] + ); $this->tokenProvider->invalidateToken($token); // Password has changed or user was disabled -> log user out return false; @@ -790,18 +850,46 @@ private function validateToken($token, $user = null) { try { $dbToken = $this->tokenProvider->getToken($token); } catch (InvalidTokenException $ex) { + $this->logger->debug( + 'token {token}, not found', + ['app' => __METHOD__, 'token' => $this->hashToken($token)] + ); return false; } + $this->logger->debug( + 'token {token} with token id {tokenId} found, validating', + ['app' => __METHOD__, 'token' => $this->hashToken($token), 'tokenId' => $dbToken->getId()] + ); + // Check if login names match if ($user !== null && $dbToken->getLoginName() !== $user) { // TODO: this makes it impossible to use different login names on browser and client // e.g. login by e-mail 'user@example.com' on browser for generating the token will not // allow to use the client token with the login name 'user'. + $this->logger->error( + 'user {user} does not match login {tokenLogin} of user {tokenUid} in token {token} with token id {tokenId}', + [ + 'app' => __METHOD__, + 'user' => $user, + 'tokenUid' => $dbToken->getLoginName(), + 'tokenLogin' => $dbToken->getLoginName(), + 'token' => $this->hashToken($token), + 'tokenId' => $dbToken->getId() + ] + ); return false; } if (!$this->checkTokenCredentials($dbToken, $token)) { + $this->logger->error( + 'invalid credentials in token {token} with token id {tokenId}', + [ + 'app' => __METHOD__, + 'token' => $this->hashToken($token), + 'tokenId' => $dbToken->getId() + ] + ); return false; } @@ -833,7 +921,7 @@ public function tryTokenLogin(IRequest $request) { if (!$this->loginWithToken($token)) { return false; } - if(!$this->validateToken($token)) { + if (!$this->validateToken($token)) { return false; } return true; @@ -908,6 +996,10 @@ protected function loginUser($user, $password) { * @return bool */ public function loginWithCookie($uid, $currentToken) { + $this->logger->debug( + 'regenerating session id for uid {uid}, currentToken {currentToken}', + ['app' => __METHOD__, 'uid' => $uid, 'currentToken' => $currentToken] + ); $this->session->regenerateId(); $this->manager->emit('\OC\User', 'preRememberedLogin', [$uid]); $user = $this->manager->get($uid); @@ -958,7 +1050,7 @@ public function logout() { try { $this->tokenProvider->invalidateToken($this->session->getId()); } catch (SessionNotAvailableException $ex) { - + $this->logger->logException($ex, ['app' => __METHOD__]); } } $this->setUser(null); @@ -1077,10 +1169,20 @@ protected function getAuthModules($includeBuiltIn) { /** * This method triggers symfony event for failed login + * * @param string $user */ protected function emitFailedLogin($user) { $loginFailedEvent = new GenericEvent(null, ['user' => $user]); $this->eventDispatcher->dispatch('user.loginfailed', $loginFailedEvent); } + + /** + * @param string $token + * @return string + */ + private function hashToken($token) { + $secret = $this->config->getSystemValue('secret'); + return \hash('sha512', $token . $secret); + } }