Skip to content

Commit 6fa5011

Browse files
ChristophWurstChristophWurst
committed
fix(session): Log when session_* calls are slow
Signed-off-by: Christoph Wurst <christoph@winzerhof-wurst.at>
1 parent 86d6bc9 commit 6fa5011

File tree

9 files changed

+51
-35
lines changed

9 files changed

+51
-35
lines changed

‎cron.php‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -61,7 +61,7 @@
6161
Server::get(ISession::class)->close();
6262

6363
// initialize a dummy memory session
64-
$session = new \OC\Session\Memory('');
64+
$session = new \OC\Session\Memory();
6565
$cryptoWrapper = \OC::$server->getSessionCryptoWrapper();
6666
$session = $cryptoWrapper->wrapSession($session);
6767
\OC::$server->setSession($session);

‎lib/base.php‎

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -388,7 +388,10 @@ public static function initSession(): void {
388388

389389
try {
390390
// set the session name to the instance id - which is unique
391-
$session = new \OC\Session\Internal($sessionName);
391+
$session = new \OC\Session\Internal(
392+
$sessionName,
393+
logger('core'),
394+
);
392395

393396
$cryptoWrapper = Server::get(\OC\Session\CryptoWrapper::class);
394397
$session = $cryptoWrapper->wrapSession($session);

‎lib/private/Server.php‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -487,7 +487,7 @@ public function __construct($webRoot, \OC\Config $config) {
487487

488488
$this->registerService(\OC\User\Session::class, function (Server $c) {
489489
$manager = $c->get(IUserManager::class);
490-
$session = new \OC\Session\Memory('');
490+
$session = new \OC\Session\Memory();
491491
$timeFactory = new TimeFactory();
492492
// Token providers might require a working database. This code
493493
// might however be called when Nextcloud is not yet setup.

‎lib/private/Session/Internal.php‎

Lines changed: 28 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -11,7 +11,11 @@
1111

1212
use OC\Authentication\Token\IProvider;
1313
use OCP\Authentication\Exceptions\InvalidTokenException;
14+
use OCP\ILogger;
1415
use OCP\Session\Exceptions\SessionNotAvailableException;
16+
use Psr\Log\LoggerInterface;
17+
use function call_user_func_array;
18+
use function microtime;
1519

1620
/**
1721
* Class Internal
@@ -25,7 +29,8 @@ class Internal extends Session {
2529
* @param string $name
2630
* @throws \Exception
2731
*/
28-
public function __construct(string $name) {
32+
public function __construct(string $name,
33+
private LoggerInterface $logger) {
2934
set_error_handler([$this, 'trapError']);
3035
$this->invoke('session_name', [$name]);
3136
$this->invoke('session_cache_limiter', ['']);
@@ -184,11 +189,31 @@ public function trapError(int $errorNumber, string $errorString) {
184189
*/
185190
private function invoke(string $functionName, array $parameters = [], bool $silence = false) {
186191
try {
192+
$timeBefore = microtime(true);
187193
if ($silence) {
188-
return @call_user_func_array($functionName, $parameters);
194+
$result = @call_user_func_array($functionName, $parameters);
189195
} else {
190-
return call_user_func_array($functionName, $parameters);
196+
$result = call_user_func_array($functionName, $parameters);
191197
}
198+
$timeAfter = microtime(true);
199+
$timeSpent = $timeAfter - $timeBefore;
200+
if ($timeSpent > 0.1) {
201+
$logLevel = match (true) {
202+
$timeSpent > 25 => ILogger::ERROR,
203+
$timeSpent > 10 => ILogger::WARN,
204+
$timeSpent > 0.5 => ILogger::INFO,
205+
default => ILogger::DEBUG,
206+
};
207+
$this->logger->log(
208+
$logLevel,
209+
"Slow session operation $functionName detected",
210+
[
211+
'parameters' => $parameters,
212+
'timeSpent' => $timeSpent,
213+
],
214+
);
215+
}
216+
return $result;
192217
} catch (\Error $e) {
193218
$this->trapError($e->getCode(), $e->getMessage());
194219
}

‎lib/private/Session/Memory.php‎

Lines changed: 0 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -20,11 +20,6 @@
2020
class Memory extends Session {
2121
protected $data;
2222

23-
public function __construct(string $name) {
24-
//no need to use $name since all data is already scoped to this instance
25-
$this->data = [];
26-
}
27-
2823
/**
2924
* @param string $key
3025
* @param integer $value

‎lib/private/Session/Session.php‎

Lines changed: 0 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -19,13 +19,6 @@ abstract class Session implements \ArrayAccess, ISession {
1919
*/
2020
protected $sessionClosed = false;
2121

22-
/**
23-
* $name serves as a namespace for the session keys
24-
*
25-
* @param string $name
26-
*/
27-
abstract public function __construct(string $name);
28-
2922
/**
3023
* @param mixed $offset
3124
* @return bool

‎tests/lib/Session/CryptoSessionDataTest.php‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -20,7 +20,7 @@ class CryptoSessionDataTest extends Session {
2020
protected function setUp(): void {
2121
parent::setUp();
2222

23-
$this->wrappedSession = new \OC\Session\Memory($this->getUniqueID());
23+
$this->wrappedSession = new \OC\Session\Memory();
2424
$this->crypto = $this->createMock(ICrypto::class);
2525
$this->crypto->expects($this->any())
2626
->method('encrypt')

‎tests/lib/Session/MemoryTest.php‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -11,10 +11,10 @@
1111
class MemoryTest extends Session {
1212
protected function setUp(): void {
1313
parent::setUp();
14-
$this->instance = new \OC\Session\Memory($this->getUniqueID());
14+
$this->instance = new \OC\Session\Memory();
1515
}
1616

17-
17+
1818
public function testThrowsExceptionOnGetId() {
1919
$this->expectException(\OCP\Session\Exceptions\SessionNotAvailableException::class);
2020

‎tests/lib/User/SessionTest.php‎

Lines changed: 14 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -114,7 +114,7 @@ public function isLoggedInData() {
114114
* @dataProvider isLoggedInData
115115
*/
116116
public function testIsLoggedIn($isLoggedIn) {
117-
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
117+
$session = $this->createMock(Memory::class);
118118

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

@@ -132,7 +132,7 @@ public function testIsLoggedIn($isLoggedIn) {
132132
}
133133

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

153153
public function testLoginValidPasswordEnabled() {
154-
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
154+
$session = $this->createMock(Memory::class);
155155
$session->expects($this->once())
156156
->method('regenerateId');
157157
$this->tokenProvider->expects($this->once())
@@ -228,7 +228,7 @@ public function testLoginValidPasswordEnabled() {
228228
public function testLoginValidPasswordDisabled() {
229229
$this->expectException(LoginException::class);
230230

231-
$session = $this->getMockBuilder(Memory::class)->setConstructorArgs([''])->getMock();
231+
$session = $this->createMock(Memory::class);
232232
$session->expects($this->never())
233233
->method('set');
234234
$session->expects($this->once())
@@ -270,7 +270,7 @@ public function testLoginValidPasswordDisabled() {
270270
}
271271

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

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

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

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

@@ -607,7 +607,7 @@ public function testTryTokenLoginSessionIdTokenNotFound(): void {
607607
}
608608

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

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

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

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

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

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

888-
$session2 = new Memory('');
888+
$session2 = new Memory();
889889
$session2->set('user_id', 'bar');
890890
$userSession->setSession($session2);
891891
$this->assertEquals($users['bar'], $userSession->getUser());

0 commit comments

Comments
 (0)