Skip to content

improve logging #402

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

Draft
wants to merge 1 commit into
base: main
Choose a base branch
from
Draft

improve logging #402

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
125 changes: 115 additions & 10 deletions lib/Controller/WhiteboardController.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@
use OCP\AppFramework\Http\Attribute\PublicPage;
use OCP\AppFramework\Http\DataResponse;
use OCP\IRequest;
use Psr\Log\LoggerInterface;

/**
* @psalm-suppress UndefinedClass
Expand All @@ -39,6 +40,7 @@
private WhiteboardContentService $contentService,
private ExceptionService $exceptionService,
private ConfigService $configService,
private LoggerInterface $logger,
) {
parent::__construct($appName, $request);
}
Expand All @@ -48,15 +50,60 @@
#[PublicPage]
public function show(int $fileId): DataResponse {
try {
$jwt = $this->getJwtFromRequest();
$this->logger->warning('WhiteboardController::show - Request for fileId: ' . $fileId, [
'file_id' => $fileId,
'request_params' => $this->request->getParams()
]);

$userId = $this->jwtService->getUserIdFromJWT($jwt);
$jwt = $this->getJwtFromRequest();

$user = $this->getUserFromIdServiceFactory->create($userId)->getUser();
$this->logger->warning('JWT token retrieved, attempting to extract user ID');

$file = $this->getFileServiceFactory->create($user, $fileId)->getFile();
$userId = $this->jwtService->getUserIdFromJWT($jwt);

$data = $this->contentService->getContent($file);
$this->logger->warning('User ID extracted from JWT: ' . $userId);

try {
$user = $this->getUserFromIdServiceFactory->create($userId)->getUser();
} catch (Exception $e) {
$this->logger->error('Failed to create user object for: ' . $userId, [
'error' => $e->getMessage()
]);
throw $e;
}

$this->logger->warning('User object created for: ' . $userId);

try {
$file = $this->getFileServiceFactory->create($user, $fileId)->getFile();
} catch (Exception $e) {
$this->logger->error('Failed to retrieve file for fileId: ' . $fileId, [
'error' => $e->getMessage()
]);
throw $e;
}

$this->logger->warning('File retrieved for fileId: ' . $fileId);

try {
$data = $this->contentService->getContent($file);
} catch (Exception $e) {
$this->logger->error('Failed to retrieve content for file', [
'file_id' => $fileId,
'error' => $e->getMessage()
]);
throw $e;
}

$this->logger->warning('Content retrieved for file', [
'file_id' => $fileId,
'data_size' => is_array($data) ? count($data) : 'not array'

Check failure on line 100 in lib/Controller/WhiteboardController.php

View workflow job for this annotation

GitHub Actions / static-psalm-analysis 

lib/Controller/WhiteboardController.php:100:53: TypeDoesNotContainType: Type array<array-key, mixed> for $data is always !array<array-key, mixed> (see https://psalm.dev/056)

Check failure on line 100 in lib/Controller/WhiteboardController.php

View workflow job for this annotation

GitHub Actions / static-psalm-analysis 

lib/Controller/WhiteboardController.php:100:20: RedundantCondition: Type array<array-key, mixed> for $data is always array<array-key, mixed> (see https://psalm.dev/122)
]);

$this->logger->warning('Content retrieved for file', [
'file_id' => $fileId,
'data_size' => is_array($data) ? count($data) : 'not array'

Check failure on line 105 in lib/Controller/WhiteboardController.php

View workflow job for this annotation

GitHub Actions / static-psalm-analysis 

lib/Controller/WhiteboardController.php:105:53: TypeDoesNotContainType: Type array<array-key, mixed> for $data is always !array<array-key, mixed> (see https://psalm.dev/056)

Check failure on line 105 in lib/Controller/WhiteboardController.php

View workflow job for this annotation

GitHub Actions / static-psalm-analysis 

lib/Controller/WhiteboardController.php:105:20: RedundantCondition: Type array<array-key, mixed> for $data is always array<array-key, mixed> (see https://psalm.dev/122)
]);

return new DataResponse(['data' => $data]);
} catch (Exception $e) {
Expand All @@ -69,15 +116,55 @@
#[PublicPage]
public function update(int $fileId, array $data): DataResponse {
try {
$this->validateBackendSharedToken($fileId);
$this->logger->warning('WhiteboardController::update - Request for fileId: ' . $fileId, [
'file_id' => $fileId,
'request_params' => json_encode(substr(json_encode($this->request->getParams()), 0, 500)) . '...'
]);

$userId = $this->getUserIdFromRequest();
$this->validateBackendSharedToken($fileId);

$user = $this->getUserFromIdServiceFactory->create($userId)->getUser();
$this->logger->warning('Backend shared token validated for fileId: ' . $fileId);

$file = $this->getFileServiceFactory->create($user, $fileId)->getFile();
$userId = $this->getUserIdFromRequest();

$this->contentService->updateContent($file, $data);
$this->logger->warning('User ID extracted from request: ' . $userId);

try {
$user = $this->getUserFromIdServiceFactory->create($userId)->getUser();
} catch (Exception $e) {
$this->logger->error('Failed to create user object for: ' . $userId, [
'error' => $e->getMessage()
]);
throw $e;
}

$this->logger->warning('User object created for: ' . $userId);

try {
$file = $this->getFileServiceFactory->create($user, $fileId)->getFile();
} catch (Exception $e) {
$this->logger->error('Failed to retrieve file for fileId: ' . $fileId, [
'error' => $e->getMessage()
]);
throw $e;
}

$this->logger->warning('File retrieved for fileId: ' . $fileId);

try {
$this->contentService->updateContent($file, $data);
} catch (Exception $e) {
$this->logger->error('Failed to update content for file', [
'file_id' => $fileId,
'error' => $e->getMessage()
]);
throw $e;
}

$this->logger->warning('Content updated for file', [
'file_id' => $fileId,
'data_size' => count($data)
]);

return new DataResponse(['status' => 'success']);
} catch (Exception $e) {
Expand All @@ -88,6 +175,7 @@
private function getJwtFromRequest(): string {
$authHeader = $this->request->getHeader('Authorization');
if (sscanf($authHeader, 'Bearer %s', $jwt) !== 1) {
$this->logger->error('Invalid JWT format in Authorization header');
throw new UnauthorizedException();
}
return (string)$jwt;
Expand All @@ -100,21 +188,38 @@
private function validateBackendSharedToken(int $fileId): void {
$backendSharedToken = $this->request->getHeader('X-Whiteboard-Auth');
if (!$backendSharedToken || !$this->verifySharedToken($backendSharedToken, $fileId)) {
$this->logger->error('Invalid backend shared token', [
'file_id' => $fileId,
'token_present' => !empty($backendSharedToken),
'token_length' => strlen((string)$backendSharedToken)

Check failure on line 194 in lib/Controller/WhiteboardController.php

View workflow job for this annotation

GitHub Actions / static-psalm-analysis 

lib/Controller/WhiteboardController.php:194:30: RedundantCast: Redundant cast to string (see https://psalm.dev/262)
]);

throw new InvalidUserException('Invalid backend shared token');
}

$this->logger->warning('Backend shared token validated successfully for fileId: ' . $fileId);
}

private function verifySharedToken(string $token, int $fileId): bool {
[$roomId, $timestamp, $signature] = explode(':', $token);

if ($roomId !== (string)$fileId) {
return false;
} else {
$this->logger->warning('Room ID matches file ID: ' . $fileId);
}

$sharedSecret = $this->configService->getWhiteboardSharedSecret();

$this->logger->warning('Shared secret retrieved, length: ' . strlen($sharedSecret));

$payload = "$roomId:$timestamp";
$expectedSignature = hash_hmac('sha256', $payload, $sharedSecret);

$this->logger->warning('Token validation', [
'token_valid' => hash_equals($expectedSignature, $signature)
]);

return hash_equals($expectedSignature, $signature);
}
}
47 changes: 45 additions & 2 deletions lib/Service/ExceptionService.php
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -16,35 +16,78 @@
use OCP\AppFramework\Http\DataResponse;
use OCP\Files\NotFoundException;
use OCP\Files\NotPermittedException;
use Psr\Log\LoggerInterface;

/**
* @psalm-suppress UndefinedClass
*/
final class ExceptionService {
public function __construct(
private LoggerInterface $logger,
) {
}

public function handleException(Exception $e): DataResponse {
$statusCode = $this->getStatusCode($e);
$message = $this->getMessage($e);

// Log the exception with context for debugging
$this->logger->error('Exception handled: ' . get_class($e), [
'message' => $e->getMessage(),
'code' => $e->getCode(),
'file' => $e->getFile(),
'line' => $e->getLine(),
'status_code' => $statusCode,
'user_message' => $message,
'trace' => $this->getTraceAsString($e),
]);

return new DataResponse(['message' => $message], $statusCode);
}

private function getStatusCode(Exception $e): int {
return match (true) {
$statusCode = match (true) {
$e instanceof NotFoundException => Http::STATUS_NOT_FOUND,
$e instanceof NotPermittedException => Http::STATUS_FORBIDDEN,
$e instanceof UnauthorizedException => Http::STATUS_UNAUTHORIZED,
$e instanceof InvalidUserException => Http::STATUS_BAD_REQUEST,
default => (int)($e->getCode() ?: Http::STATUS_INTERNAL_SERVER_ERROR),
};

$this->logger->warning('Determined status code for exception', [
'exception_type' => get_class($e),
'status_code' => $statusCode,
]);

return $statusCode;
}

private function getMessage(Exception $e): string {
return match (true) {
$message = match (true) {
$e instanceof NotFoundException => 'File not found',
$e instanceof NotPermittedException => 'Permission denied',
$e instanceof UnauthorizedException => 'Unauthorized',
$e instanceof InvalidUserException => 'Invalid user',
default => $e->getMessage() ?: 'An error occurred',
};

$this->logger->warning('Generated user-facing message', [
'exception_type' => get_class($e),
'original_message' => $e->getMessage(),
'user_message' => $message,
]);

return $message;
}

private function getTraceAsString(Exception $e): string {
$traceLines = explode("\n", $e->getTraceAsString());
$limitedTrace = array_slice($traceLines, 0, 10);

if (count($traceLines) > 10) {
$limitedTrace[] = '... ' . (count($traceLines) - 10) . ' more lines truncated';
}

return implode("\n", $limitedTrace);
}
}
Loading
Loading