Skip to content

[DX] Attempt to improve logging messages with parameters #13418

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.

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

Closed
wants to merge 4 commits into from
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
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
Original file line number Diff line number Diff line change
Expand Up @@ -146,7 +146,7 @@ public function getNotCalledListeners()
$allListeners = $this->getListeners();
} catch (\Exception $e) {
if (null !== $this->logger) {
$this->logger->info(sprintf('An exception was thrown while getting the uncalled listeners (%s)', $e->getMessage()), array('exception' => $e));
$this->logger->info('An exception was thrown while getting the uncalled listeners.', array('exception' => $e));
}

// unable to retrieve the uncalled listeners
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,7 @@ public function getController(Request $request)
{
if (!$controller = $request->attributes->get('_controller')) {
if (null !== $this->logger) {
$this->logger->warning('Unable to look for the controller as the "_controller" parameter is missing');
$this->logger->warning('Unable to look for the controller as the "_controller" parameter is missing.');
}

return false;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -140,7 +140,7 @@ public function onKernelRequest(GetResponseEvent $event)
}

if (null !== $this->logger) {
$this->logger->info(sprintf('Matched route "%s"', $parameters['_route']), $parameters);
$this->logger->info(sprintf('Matched route "%s".', $parameters['_route']), $parameters);
}

$request->attributes->add($parameters);
Expand Down
2 changes: 1 addition & 1 deletion src/Symfony/Component/HttpKernel/Profiler/Profiler.php
Original file line number Diff line number Diff line change
Expand Up @@ -117,7 +117,7 @@ public function saveProfile(Profile $profile)
}

if (!($ret = $this->storage->write($profile)) && null !== $this->logger) {
$this->logger->warning('Unable to store the profiler information.');
$this->logger->warning('Unable to store the profiler information.', array('configured_storage' => get_class($this->storage)));
}

return $ret;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,7 +20,7 @@ class ControllerResolverTest extends \PHPUnit_Framework_TestCase
public function testGetControllerWithoutControllerParameter()
{
$logger = $this->getMock('Psr\Log\LoggerInterface');
$logger->expects($this->once())->method('warning')->with('Unable to look for the controller as the "_controller" parameter is missing');
$logger->expects($this->once())->method('warning')->with('Unable to look for the controller as the "_controller" parameter is missing.');
$resolver = $this->createControllerResolver($logger);

$request = Request::create('/');
Expand Down
8 changes: 4 additions & 4 deletions src/Symfony/Component/Security/Acl/Voter/AclVoter.php
Original file line number Diff line number Diff line change
Expand Up @@ -64,7 +64,7 @@ public function vote(TokenInterface $token, $object, array $attributes)

if (null === $object) {
if (null !== $this->logger) {
$this->logger->debug(sprintf('Object identity unavailable. Voting to %s', $this->allowIfObjectIdentityUnavailable ? 'grant access' : 'abstain'));
$this->logger->debug(sprintf('Object identity unavailable. Voting to %s.', $this->allowIfObjectIdentityUnavailable ? 'grant access' : 'abstain'));
}

return $this->allowIfObjectIdentityUnavailable ? self::ACCESS_GRANTED : self::ACCESS_ABSTAIN;
Expand All @@ -79,7 +79,7 @@ public function vote(TokenInterface $token, $object, array $attributes)
$oid = $object;
} elseif (null === $oid = $this->objectIdentityRetrievalStrategy->getObjectIdentity($object)) {
if (null !== $this->logger) {
$this->logger->debug(sprintf('Object identity unavailable. Voting to %s', $this->allowIfObjectIdentityUnavailable ? 'grant access' : 'abstain'));
$this->logger->debug(sprintf('Object identity unavailable. Voting to %s.', $this->allowIfObjectIdentityUnavailable ? 'grant access' : 'abstain'));
}

return $this->allowIfObjectIdentityUnavailable ? self::ACCESS_GRANTED : self::ACCESS_ABSTAIN;
Expand All @@ -96,13 +96,13 @@ public function vote(TokenInterface $token, $object, array $attributes)

if (null === $field && $acl->isGranted($masks, $sids, false)) {
if (null !== $this->logger) {
$this->logger->debug('ACL found, permission granted. Voting to grant access');
$this->logger->debug('ACL found, permission granted. Voting to grant access.');
}

return self::ACCESS_GRANTED;
} elseif (null !== $field && $acl->isFieldGranted($field, $masks, $sids, false)) {
if (null !== $this->logger) {
$this->logger->debug('ACL found, permission granted. Voting to grant access');
$this->logger->debug('ACL found, permission granted. Voting to grant access.');
}

return self::ACCESS_GRANTED;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -92,7 +92,7 @@ public function onAuthenticationFailure(Request $request, AuthenticationExceptio

if ($this->options['failure_forward']) {
if (null !== $this->logger) {
$this->logger->debug(sprintf('Forwarding to %s', $this->options['failure_path']));
$this->logger->debug('Authentication failure, forward triggered.', array('failure_path' => $this->options['failure_path']));
}

$subRequest = $this->httpUtils->createRequest($request, $this->options['failure_path']);
Expand All @@ -102,7 +102,7 @@ public function onAuthenticationFailure(Request $request, AuthenticationExceptio
}

if (null !== $this->logger) {
$this->logger->debug(sprintf('Redirecting to %s', $this->options['failure_path']));
$this->logger->debug('Authentication failure, redirect triggered.', array('failure_path' => $this->options['failure_path']));
}

$request->getSession()->set(Security::AUTHENTICATION_ERROR, $exception);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -57,7 +57,7 @@ public function onAuthenticationSuccess(Request $request, TokenInterface $token)
{
if ($this->simpleAuthenticator instanceof AuthenticationSuccessHandlerInterface) {
if ($this->logger) {
$this->logger->debug(sprintf('Using the %s object as authentication success handler', get_class($this->simpleAuthenticator)));
$this->logger->debug('Selected an authentication success handler.', array('handler' => get_class($this->simpleAuthenticator)));
}

$response = $this->simpleAuthenticator->onAuthenticationSuccess($request, $token);
Expand All @@ -71,7 +71,7 @@ public function onAuthenticationSuccess(Request $request, TokenInterface $token)
}

if ($this->logger) {
$this->logger->debug('Fallback to the default authentication success handler');
$this->logger->debug('Fallback to the default authentication success handler.');
}

return $this->successHandler->onAuthenticationSuccess($request, $token);
Expand All @@ -84,7 +84,7 @@ public function onAuthenticationFailure(Request $request, AuthenticationExceptio
{
if ($this->simpleAuthenticator instanceof AuthenticationFailureHandlerInterface) {
if ($this->logger) {
$this->logger->debug(sprintf('Using the %s object as authentication failure handler', get_class($this->simpleAuthenticator)));
$this->logger->debug('Selected an authentication failure handler.', array('handler' => get_class($this->simpleAuthenticator)));
}

$response = $this->simpleAuthenticator->onAuthenticationFailure($request, $exception);
Expand All @@ -98,7 +98,7 @@ public function onAuthenticationFailure(Request $request, AuthenticationExceptio
}

if ($this->logger) {
$this->logger->debug('Fallback to the default authentication failure handler');
$this->logger->debug('Fallback to the default authentication failure handler.');
}

return $this->failureHandler->onAuthenticationFailure($request, $exception);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -54,7 +54,7 @@ public function start(Request $request, AuthenticationException $authException =
}

if (null !== $this->logger) {
$this->logger->debug(sprintf('WWW-Authenticate header sent to user agent: "%s"', $authenticateHeader));
$this->logger->debug('WWW-Authenticate header sent.', array('header' => $authenticateHeader));
}

$response = new Response();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -193,7 +193,7 @@ abstract protected function attemptAuthentication(Request $request);
private function onFailure(Request $request, AuthenticationException $failed)
{
if (null !== $this->logger) {
$this->logger->info(sprintf('Authentication request failed: %s', $failed->getMessage()));
$this->logger->info('Authentication request failed.', array('exception' => $failed));
}

$token = $this->tokenStorage->getToken();
Expand All @@ -213,7 +213,7 @@ private function onFailure(Request $request, AuthenticationException $failed)
private function onSuccess(Request $request, TokenInterface $token)
{
if (null !== $this->logger) {
$this->logger->info(sprintf('User "%s" has been authenticated successfully', $token->getUsername()));
$this->logger->info('User has been authenticated successfully.', array('username' => $token->getUsername()));
}

$this->tokenStorage->setToken($token);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -56,10 +56,6 @@ final public function handle(GetResponseEvent $event)
{
$request = $event->getRequest();

if (null !== $this->logger) {
$this->logger->debug(sprintf('Checking secure context token: %s', $this->tokenStorage->getToken()));
}

try {
list($user, $credentials) = $this->getPreAuthenticatedData($request);
} catch (BadCredentialsException $exception) {
Expand All @@ -68,21 +64,25 @@ final public function handle(GetResponseEvent $event)
return;
}

if (null !== $this->logger) {
$this->logger->debug('Checking current security token.', array('token' => (string) $this->tokenStorage->getToken()));
}

if (null !== $token = $this->tokenStorage->getToken()) {
if ($token instanceof PreAuthenticatedToken && $this->providerKey == $token->getProviderKey() && $token->isAuthenticated() && $token->getUsername() === $user) {
return;
}
}

if (null !== $this->logger) {
$this->logger->debug(sprintf('Trying to pre-authenticate user "%s"', $user));
$this->logger->debug('Trying to pre-authenticate user.', array('username' => (string) $user));
}

try {
$token = $this->authenticationManager->authenticate(new PreAuthenticatedToken($user, $credentials, $this->providerKey));

if (null !== $this->logger) {
$this->logger->info(sprintf('Authentication success: %s', $token));
$this->logger->info('Pre-authentication successful.', array('token' => (string) $token));
}
$this->tokenStorage->setToken($token);

Expand All @@ -107,7 +107,7 @@ private function clearToken(AuthenticationException $exception)
$this->tokenStorage->setToken(null);

if (null !== $this->logger) {
$this->logger->info(sprintf("Cleared security context due to exception: %s", $exception->getMessage()));
$this->logger->info('Cleared security token due to an exception.', array('exception' => $exception));
}
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -59,11 +59,11 @@ public function handle(GetResponseEvent $event)
$this->tokenStorage->setToken($token);

if (null !== $this->logger) {
$this->logger->info('Populated TokenStorage with an anonymous Token');
$this->logger->info('Populated the TokenStorage with an anonymous Token.');
}
} catch (AuthenticationException $failed) {
if (null !== $this->logger) {
$this->logger->info(sprintf('Anonymous authentication failed: %s', $failed->getMessage()));
$this->logger->info('Anonymous authentication failed.', array('exception' => $failed));
}
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -67,7 +67,7 @@ public function handle(GetResponseEvent $event)
}

if (null !== $this->logger) {
$this->logger->info(sprintf('Basic Authentication Authorization header found for user "%s"', $username));
$this->logger->info('Basic authentication Authorization header found for user.', array('username' => $username));
}

try {
Expand All @@ -80,7 +80,7 @@ public function handle(GetResponseEvent $event)
}

if (null !== $this->logger) {
$this->logger->info(sprintf('Authentication request failed for user "%s": %s', $username, $failed->getMessage()));
$this->logger->info('Basic authentication failed for user.', array('username' => $username, 'exception' => $failed));
}

if ($this->ignoreFailure) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -44,11 +44,11 @@ public function handle(GetResponseEvent $event)
{
$request = $event->getRequest();

list($attributes, $channel) = $this->map->getPatterns($request);
list(, $channel) = $this->map->getPatterns($request);

if ('https' === $channel && !$request->isSecure()) {
if (null !== $this->logger) {
$this->logger->info('Redirecting to HTTPS');
$this->logger->info('Redirecting to HTTPS.');
}

$response = $this->authenticationEntryPoint->start($request);
Expand All @@ -60,7 +60,7 @@ public function handle(GetResponseEvent $event)

if ('http' === $channel && $request->isSecure()) {
if (null !== $this->logger) {
$this->logger->info('Redirecting to HTTP');
$this->logger->info('Redirecting to HTTP.');
}

$response = $this->authenticationEntryPoint->start($request);
Expand Down
30 changes: 14 additions & 16 deletions src/Symfony/Component/Security/Http/Firewall/ContextListener.php
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ class ContextListener implements ListenerInterface
{
private $tokenStorage;
private $contextKey;
private $sessionKey;
private $logger;
private $userProviders;
private $dispatcher;
Expand All @@ -54,12 +55,13 @@ public function __construct(TokenStorageInterface $tokenStorage, array $userProv
$this->tokenStorage = $tokenStorage;
$this->userProviders = $userProviders;
$this->contextKey = $contextKey;
$this->sessionKey = '_security_'.$contextKey;
$this->logger = $logger;
$this->dispatcher = $dispatcher;
}

/**
* Reads the SecurityContext from the session.
* Reads the Security Token from the session.
*
* @param GetResponseEvent $event A GetResponseEvent instance
*/
Expand All @@ -73,7 +75,7 @@ public function handle(GetResponseEvent $event)
$request = $event->getRequest();
$session = $request->hasPreviousSession() ? $request->getSession() : null;

if (null === $session || null === $token = $session->get('_security_'.$this->contextKey)) {
if (null === $session || null === $token = $session->get($this->sessionKey)) {
$this->tokenStorage->setToken(null);

return;
Expand All @@ -82,14 +84,14 @@ public function handle(GetResponseEvent $event)
$token = unserialize($token);

if (null !== $this->logger) {
$this->logger->debug('Read SecurityContext from the session');
$this->logger->debug('Read existing security token from the session.', array('key' => $this->sessionKey));
}

if ($token instanceof TokenInterface) {
$token = $this->refreshUser($token);
} elseif (null !== $token) {
if (null !== $this->logger) {
$this->logger->warning(sprintf('Session includes a "%s" where a security token is expected', is_object($token) ? get_class($token) : gettype($token)));
$this->logger->warning('Expected a security token from the session, got something else.', array('key' => $this->sessionKey, 'received' => $token));
}

$token = null;
Expand All @@ -113,10 +115,6 @@ public function onKernelResponse(FilterResponseEvent $event)
return;
}

if (null !== $this->logger) {
$this->logger->debug('Write SecurityContext in the session');
}

$request = $event->getRequest();
$session = $request->getSession();

Expand All @@ -126,10 +124,14 @@ public function onKernelResponse(FilterResponseEvent $event)

if ((null === $token = $this->tokenStorage->getToken()) || ($token instanceof AnonymousToken)) {
if ($request->hasPreviousSession()) {
$session->remove('_security_'.$this->contextKey);
$session->remove($this->sessionKey);
}
} else {
$session->set('_security_'.$this->contextKey, serialize($token));
$session->set($this->sessionKey, serialize($token));

if (null !== $this->logger) {
$this->logger->debug('Stored the security token in the session.', array('key' => $this->sessionKey));
}
}
}

Expand All @@ -149,25 +151,21 @@ protected function refreshUser(TokenInterface $token)
return $token;
}

if (null !== $this->logger) {
$this->logger->debug(sprintf('Reloading user from user provider.'));
}

foreach ($this->userProviders as $provider) {
try {
$refreshedUser = $provider->refreshUser($user);
$token->setUser($refreshedUser);

if (null !== $this->logger) {
$this->logger->debug(sprintf('Username "%s" was reloaded from user provider.', $refreshedUser->getUsername()));
$this->logger->debug('User was reloaded from a user provider.', array('username' => $refreshedUser->getUsername(), 'provider' => get_class($provider)));
}

return $token;
} catch (UnsupportedUserException $unsupported) {
// let's try the next user provider
} catch (UsernameNotFoundException $notFound) {
if (null !== $this->logger) {
$this->logger->warning(sprintf('Username "%s" could not be found.', $notFound->getUsername()));
$this->logger->warning('Username could not be found in the selected user provider.', array('username' => $notFound->getUsername(), 'provider' => get_class($provider)));
}

return;
Expand Down
Loading