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.

Sign up for GitHub

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

Jump to bottom

fix(session): Log when session_* calls are slow #46106

Merged
merged 1 commit into from
Aug 7, 2024
Merged

fix(session): Log when session_* calls are slow #46106

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion cron.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -61,7 +61,7 @@
Server::get(ISession::class)->close();

// initialize a dummy memory session
$session = new \OC\Session\Memory('');
$session = new \OC\Session\Memory();
$cryptoWrapper = \OC::$server->getSessionCryptoWrapper();
$session = $cryptoWrapper->wrapSession($session);
\OC::$server->setSession($session);
Expand Down
5 changes: 4 additions & 1 deletion lib/base.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -141,7 +141,7 @@
// slash which is required by URL generation.
if (isset($_SERVER['REQUEST_URI']) && $_SERVER['REQUEST_URI'] === \OC::$WEBROOT &&
substr($_SERVER['REQUEST_URI'], -1) !== '/') {
header('Location: '.\OC::$WEBROOT.'/');

Check failure on line 144 in lib/base.php

View workflow job for this annotation

GitHub Actions / static-code-analysis-security

TaintedHeader 

lib/base.php:144:12: TaintedHeader: Detected tainted header (see https://psalm.dev/256)
exit();
}
}
Expand Down Expand Up @@ -223,7 +223,7 @@
throw new Exception('Not installed');
} else {
$url = OC::$WEBROOT . '/index.php';
header('Location: ' . $url);

Check failure on line 226 in lib/base.php

View workflow job for this annotation

GitHub Actions / static-code-analysis-security

TaintedHeader 

lib/base.php:226:12: TaintedHeader: Detected tainted header (see https://psalm.dev/256)
}
exit();
}
Expand Down Expand Up @@ -388,7 +388,10 @@

try {
// set the session name to the instance id - which is unique
$session = new \OC\Session\Internal($sessionName);
$session = new \OC\Session\Internal(
$sessionName,
logger('core'),
);

$cryptoWrapper = Server::get(\OC\Session\CryptoWrapper::class);
$session = $cryptoWrapper->wrapSession($session);
Expand Down
2 changes: 1 addition & 1 deletion lib/private/Server.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -489,7 +489,7 @@ public function __construct($webRoot, \OC\Config $config) {

$this->registerService(\OC\User\Session::class, function (Server $c) {
$manager = $c->get(IUserManager::class);
$session = new \OC\Session\Memory('');
$session = new \OC\Session\Memory();
$timeFactory = new TimeFactory();
// Token providers might require a working database. This code
// might however be called when Nextcloud is not yet setup.
Expand Down
31 changes: 28 additions & 3 deletions lib/private/Session/Internal.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,7 +11,11 @@

use OC\Authentication\Token\IProvider;
use OCP\Authentication\Exceptions\InvalidTokenException;
use OCP\ILogger;
use OCP\Session\Exceptions\SessionNotAvailableException;
use Psr\Log\LoggerInterface;
use function call_user_func_array;
use function microtime;

/**
* Class Internal
Expand All @@ -25,7 +29,8 @@ class Internal extends Session {
* @param string $name
* @throws \Exception
*/
public function __construct(string $name) {
public function __construct(string $name,
private LoggerInterface $logger) {
set_error_handler([$this, 'trapError']);
$this->invoke('session_name', [$name]);
$this->invoke('session_cache_limiter', ['']);
Expand Down Expand Up @@ -184,11 +189,31 @@ public function trapError(int $errorNumber, string $errorString) {
*/
private function invoke(string $functionName, array $parameters = [], bool $silence = false) {
try {
$timeBefore = microtime(true);
if ($silence) {
return @call_user_func_array($functionName, $parameters);
$result = @call_user_func_array($functionName, $parameters);
} else {
return call_user_func_array($functionName, $parameters);
$result = call_user_func_array($functionName, $parameters);
}
$timeAfter = microtime(true);
$timeSpent = $timeAfter - $timeBefore;
if ($timeSpent > 0.1) {
$logLevel = match (true) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

should we add a function which takes the time list as an argument? :-X
Doing this in so many places already

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure how this can be abstracted the best way. The thresholds do not always follow the same pattern. Sometimes it's linear, other times it's exponential.

$timeSpent > 25 => ILogger::ERROR,
$timeSpent > 10 => ILogger::WARN,
$timeSpent > 0.5 => ILogger::INFO,
default => ILogger::DEBUG,
};
$this->logger->log(
$logLevel,
"Slow session operation $functionName detected",
[
'parameters' => $parameters,
'timeSpent' => $timeSpent,
],
);
}
return $result;
} catch (\Error $e) {
$this->trapError($e->getCode(), $e->getMessage());
}
Expand Down
5 changes: 0 additions & 5 deletions lib/private/Session/Memory.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,11 +20,6 @@
class Memory extends Session {
protected $data;

public function __construct(string $name) {
//no need to use $name since all data is already scoped to this instance
$this->data = [];
}

/**
* @param string $key
* @param integer $value
Expand Down
7 changes: 0 additions & 7 deletions lib/private/Session/Session.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,13 +19,6 @@ abstract class Session implements \ArrayAccess, ISession {
*/
protected $sessionClosed = false;

/**
* $name serves as a namespace for the session keys
*
* @param string $name
*/
abstract public function __construct(string $name);

/**
* @param mixed $offset
* @return bool
Expand Down
2 changes: 1 addition & 1 deletion tests/lib/Session/CryptoSessionDataTest.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@ class CryptoSessionDataTest extends Session {
protected function setUp(): void {
parent::setUp();

$this->wrappedSession = new \OC\Session\Memory($this->getUniqueID());
$this->wrappedSession = new \OC\Session\Memory();
$this->crypto = $this->createMock(ICrypto::class);
$this->crypto->expects($this->any())
->method('encrypt')
Expand Down
4 changes: 2 additions & 2 deletions tests/lib/Session/MemoryTest.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -11,10 +11,10 @@
class MemoryTest extends Session {
protected function setUp(): void {
parent::setUp();
$this->instance = new \OC\Session\Memory($this->getUniqueID());
$this->instance = new \OC\Session\Memory();
}


public function testThrowsExceptionOnGetId() {
$this->expectException(\OCP\Session\Exceptions\SessionNotAvailableException::class);

Expand Down
28 changes: 14 additions & 14 deletions tests/lib/User/SessionTest.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -114,7 +114,7 @@ public function isLoggedInData() {
* @dataProvider isLoggedInData
*/
public function testIsLoggedIn($isLoggedIn) {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);

$manager = $this->createMock(Manager::class);

Expand All @@ -132,7 +132,7 @@ public function testIsLoggedIn($isLoggedIn) {
}

public function testSetUser() {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$session->expects($this->once())
->method('set')
->with('user_id', 'foo');
Expand All @@ -151,7 +151,7 @@ public function testSetUser() {
}

public function testLoginValidPasswordEnabled() {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$session->expects($this->once())
->method('regenerateId');
$this->tokenProvider->expects($this->once())
Expand Down Expand Up @@ -228,7 +228,7 @@ public function testLoginValidPasswordEnabled() {
public function testLoginValidPasswordDisabled() {
$this->expectException(LoginException::class);

$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$session->expects($this->never())
->method('set');
$session->expects($this->once())
Expand Down Expand Up @@ -270,7 +270,7 @@ public function testLoginValidPasswordDisabled() {
}

public function testLoginInvalidPassword() {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$managerMethods = get_class_methods(Manager::class);
//keep following methods intact in order to ensure hooks are working
$mockedManagerMethods = array_diff($managerMethods, ['__construct', 'emit', 'listen']);
Expand Down Expand Up @@ -313,7 +313,7 @@ public function testLoginInvalidPassword() {
}

public function testPasswordlessLoginNoLastCheckUpdate(): void {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$managerMethods = get_class_methods(Manager::class);
// Keep following methods intact in order to ensure hooks are working
$mockedManagerMethods = array_diff($managerMethods, ['__construct', 'emit', 'listen']);
Expand Down Expand Up @@ -350,7 +350,7 @@ public function testPasswordlessLoginNoLastCheckUpdate(): void {
}

public function testLoginLastCheckUpdate(): void {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$managerMethods = get_class_methods(Manager::class);
// Keep following methods intact in order to ensure hooks are working
$mockedManagerMethods = array_diff($managerMethods, ['__construct', 'emit', 'listen']);
Expand Down Expand Up @@ -387,7 +387,7 @@ public function testLoginLastCheckUpdate(): void {
}

public function testLoginNonExisting() {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$manager = $this->createMock(Manager::class);
$userSession = new Session($manager, $session, $this->timeFactory, $this->tokenProvider, $this->config, $this->random, $this->lockdownManager, $this->logger, $this->dispatcher);

Expand Down Expand Up @@ -607,7 +607,7 @@ public function testTryTokenLoginSessionIdTokenNotFound(): void {
}

public function testRememberLoginValidToken() {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$managerMethods = get_class_methods(Manager::class);
//keep following methods intact in order to ensure hooks are working
$mockedManagerMethods = array_diff($managerMethods, ['__construct', 'emit', 'listen']);
Expand Down Expand Up @@ -696,7 +696,7 @@ public function testRememberLoginValidToken() {
}

public function testRememberLoginInvalidSessionToken() {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$managerMethods = get_class_methods(Manager::class);
//keep following methods intact in order to ensure hooks are working
$mockedManagerMethods = array_diff($managerMethods, ['__construct', 'emit', 'listen']);
Expand Down Expand Up @@ -760,7 +760,7 @@ public function testRememberLoginInvalidSessionToken() {
}

public function testRememberLoginInvalidToken() {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$managerMethods = get_class_methods(Manager::class);
//keep following methods intact in order to ensure hooks are working
$mockedManagerMethods = array_diff($managerMethods, ['__construct', 'emit', 'listen']);
Expand Down Expand Up @@ -812,7 +812,7 @@ public function testRememberLoginInvalidToken() {
}

public function testRememberLoginInvalidUser() {
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
$session = $this->createMock(Memory::class);
$managerMethods = get_class_methods(Manager::class);
//keep following methods intact in order to ensure hooks are working
$mockedManagerMethods = array_diff($managerMethods, ['__construct', 'emit', 'listen']);
Expand Down Expand Up @@ -872,7 +872,7 @@ public function testActiveUserAfterSetSession() {
return $users[$uid];
});

$session = new Memory('');
$session = new Memory();
$session->set('user_id', 'foo');
$userSession = $this->getMockBuilder(Session::class)
->setConstructorArgs([$manager, $session, $this->timeFactory, $this->tokenProvider, $this->config, $this->random, $this->lockdownManager, $this->logger, $this->dispatcher])
Expand All @@ -885,7 +885,7 @@ public function testActiveUserAfterSetSession() {

$this->assertEquals($users['foo'], $userSession->getUser());

$session2 = new Memory('');
$session2 = new Memory();
$session2->set('user_id', 'bar');
$userSession->setSession($session2);
$this->assertEquals($users['bar'], $userSession->getUser());
Expand Down
Loading