[SECURITY] AbstractAuthenticationListener.php error instead info. #28462

Warxcell · 2018-09-13T20:52:16Z

[2018-09-13 20:43:38] security.INFO: Authentication request failed. {"exception":"[object] (Symfony\\Component\\Security\\Core\\Exception\\AuthenticationServiceException(code: 0): An exception occurred while executing
 ...
 Doctrine\\DBAL\\Driver\\PDOException(code: 42S22): SQLSTATE[42S22]: Column not found: 1054 Unknown column 't0.phone' in 'field list' at

Definitely I think this is NOT info, but error.
And since it's info, it's not logged in production because of fingers_crossed with action_level: error - so to actually see the real error behind Authentication request could not be processed due to a system problem. I had to debug on production. Very bad practice IMHO.

Q	A
Branch?	3.4
Bug fix?	yes
New feature?	no
BC breaks?	no I think
Deprecations?	no
Tests pass?	yes
Fixed tickets	...
License	MIT

``` [2018-09-13 20:43:38] security.INFO: Authentication request failed. {"exception":"[object] (Symfony\\Component\\Security\\Core\\Exception\\AuthenticationServiceException(code: 0): An exception occurred while executing ... Doctrine\\DBAL\\Driver\\PDOException(code: 42S22): SQLSTATE[42S22]: Column not found: 1054 Unknown column 't0.phone' in 'field list' at ``` Defenitely I think this is NOT info, but error. | Q | A | ------------- | --- | Branch? | 3.8 | Bug fix? | yes | New feature? | no | BC breaks? | no I think | Deprecations? | no | Tests pass? | yes | Fixed tickets | ... | License | MIT

jvasseur · 2018-09-13T21:05:57Z

This means all failed authentication attempts will now be logged as error which is not right either. We need to differentiate between errors in the authentication process and failed authentication attempts to determine the logging level here.

Warxcell · 2018-09-13T21:18:36Z

@jvasseur thank you for your response.

How do we do that? What are exceptions for non-errors?

What about that:

if ($failed instanceof \Symfony\Component\Security\Core\Exception\AuthenticationServiceException) {
      $this->logger->error('Authentication request failed.', array('exception' => $failed));
} else {
      $this->logger->info('Authentication request failed.', array('exception' => $failed));
}

at the top of that exception it says:

AuthenticationServiceException is thrown when an authentication request could not be processed due to a system problem.

jvasseur · 2018-09-13T22:01:44Z

@Warxcell checking if the exception is an instance of AuthenticationServiceException could be a good solution yes.

Use Symfony\Component\Security\Core\Exception\AuthenticationServiceException to determine logging level

Fix coding standarts

Warxcell · 2018-09-13T22:37:20Z

What I would do is in case of AuthenticationServiceException just rethrow error - so it would result in 500 Error on page, like everywhere else. (and easier debugging on dev)

But that means BC-Break - so I'm just changing the logging level.

linaori · 2018-09-14T09:28:31Z

I've done a quick search where this exception is being used.

`UserAuthenticationProvider`

This is extended by the LdapBindAuthenticationprovider and DaoAuthenticationProvider. While being an AuthenticationServiceException, this would in the future be caught by return types as it specifies @return UserInterface on retrieveUser.

One small note for this, the Dao is something that should be removed in my opinion and the Ldap variant should be re-made in Guard, but that's another issue.

Conclusion: This one should trigger an ERROR level

`DaoAuthenticationProvider`

Throws it twice, once when the return contract is broken (return is not a UserInteface) and once when a generic exception is thrown. Both of them are triggered when something is broken as the generic exception catch is superseded by a catch on UsernameNotFoundException.

Conclusion: Both should trigger an ERROR level

`DigestAuthenticationListener`

This implementation specifies that it's an ERROR level: "Digest User provider returned null, which is an interface contract violation"

Conclusion: This one should trigger an ERROR level

`UnsupportedUserException`

Caught in the ChainUserProvider
Caught in the ContextListener
Caught in the AbstractRememberMeServices

Conclusion: these are often implemented by the end-user, but we cannot guarantee they are a 500 error. According to the class itself:

This exception is thrown when an account is reloaded from a provider which doesn't support the passed implementation of UserInterface.

Which I already see being abused here. My suggestion would be to follow the class doc and make it an ERROR as well.

Final conclusion

This particular exception should in my opinion trigger an ERROR in the logs. However, it should not do this for the Authentication Failed log. That means the logging has to be adapted in a way where both can be logged separately. Perhaps this can be done via getParent() on the Exception?

nicolas-grekas · 2018-09-18T12:26:22Z

@iltar would you be able to provide a patch doing so to help @Warxcell? (or maybe it's not needed?)

linaori · 2018-09-18T17:08:14Z

I can help with a patch (reviewing), but I do not have time myself to do this in-between at the moment

Warxcell · 2018-09-19T11:54:03Z

So what should be done? If it's error log in app channel, if not - log in security channel?

nicolas-grekas · 2018-10-20T21:23:52Z

@iltar I think we need your help here :)

linaori · 2018-10-21T09:22:10Z

So what should be done? If it's error log in app channel, if not - log in security channel?

That's actually not a bad idea at all 😮

Warxcell · 2018-11-01T09:42:45Z

@iltar how can this be done? sending 2 different loggers with tag monolog.logger ?

fabpot · 2019-03-25T09:15:55Z

@linaori Might be a great PR for the upcoming hackaton :)

linaori · 2019-03-25T09:29:03Z

Do we have a label for the hackathon? It might be nice to tag a bunch of issues so we can plow through them.

javiereguiluz · 2019-03-25T10:24:07Z

@linaori yes, we've created a special label for that event:

curry684 · 2019-04-06T19:00:15Z

@linaori I've just read the entire discussion and your well researched arguments, and I'm now thinking why we're not raising the log level to ERROR as a whole as indeed our existing implementations act like that and the class is documented to work like that. I don't see the INFO case any more other than to maintain some kind of fake B/C with existing applications and bundles that somehow count on it being info.

To be honest, I don't consider that a B/C breakage as the docs were there to indicate it always should have been an error.

nicolas-grekas · 2019-04-07T18:35:51Z

(rebase needed)

…ror instead info.

…ase of symfony#28462

…stead info. Rebase of #28462 (berezuev) This PR was merged into the 4.4 branch. Discussion ---------- [SECURITY] AbstractAuthenticationListener.php error instead info. Rebase of #28462 | Q | A | ------------- | --- | Branch? | 4.4 | -- | -- | Bug fix? | yes | New feature? | no | BC breaks? | no I think | Deprecations? | no | Tests pass? | yes | Fixed tickets | ... | License | MIT Rebase of #28462. Origin description: > ``` > [2018-09-13 20:43:38] security.INFO: Authentication request failed. {"exception":"[object] (Symfony\\Component\\Security\\Core\\Exception\\AuthenticationServiceException(code: 0): An exception occurred while executing > ... > Doctrine\\DBAL\\Driver\\PDOException(code: 42S22): SQLSTATE[42S22]: Column not found: 1054 Unknown column 't0.phone' in 'field list' at > ``` > > Definitely I think this is NOT info, but error. > And since it's info, it's not logged in production because of `fingers_crossed` with `action_level: error` - so to actually see the real error behind `Authentication request could not be processed due to a system problem.` I had to debug on production. Very bad practice IMHO. Commits ------- 867eb78 [SECURITY] AbstractAuthenticationListener.php error instead info. Rebase of #28462

Fl0ux · 2019-12-05T15:48:52Z

Something seems to wrong with this commit. Now every failed login attempts are logged as errors.

[2019-12-05T11:47:47.157808+01:00] security.ERROR: Authentication request failed. {"exception":"[object] (Symfony\\Component\\Security\\Core\\Exception\\BadCredentialsException(code: 0): Bad credentials. at /home/foulques/PhpstormProjects/MonAvisCitoyenV2/vendor/symfony/security-core/Authentication/Provider/UserAuthenticationProvider.php:68)\n[previous exception] [object] (Symfony\\Component\\Security\\Core\\Exception\\UsernameNotFoundException(code: 0): User \"18691mac@yopmail.com\" not found. at /home/foulques/PhpstormProjects/MonAvisCitoyenV2/vendor/symfony/doctrine-bridge/Security/User/EntityUserProvider.php:65)"} []

... and every time I receive a mail to warn me about this...

Warxcell · 2019-12-05T16:05:42Z

@Fl0ux it's not because of that. As you can see - it's closed, not merged.

nicolas-grekas · 2019-12-05T16:07:18Z

It's merged in 87a6f04 actually.
But commenting on a closed PR will likely be ignored as there is no way to track them.

Fl0ux · 2019-12-05T16:09:01Z

Ok, I will create a new bug report in this case.

Warxcell · 2019-12-05T16:09:19Z

@nicolas-grekas but it's slightly different from my PR. I excluded these exceptions. I was logging only system errors, not every failed login because of credentials.

…nfo. Rebase of symfony#28462" This reverts commit 867eb78.

…r instead info" (larzuk91) This PR was submitted for the master branch but it was merged into the 4.4 branch instead. Discussion ---------- [Security] Revert "AbstractAuthenticationListener.php error instead info" | Q | A | ------------- | --- | Branch? | 4.4 | Bug fix? | yes | New feature? | no | Deprecations? | no | Tickets | Fix #34836 | License | MIT This reverts commit 867eb78. After that change, every failed login attempt is logged as an error. It's flooding our errors log channel Commits ------- 9d306f9 [SECURITY] Revert "AbstractAuthenticationListener.php error instead info. Rebase of #28462"

* 4.4: (21 commits) fix merge CS [FrameworkBundle][ContainerLintCommand] Improve messages when the kernel or the container is not supported [Serializer] Skip uninitialized (PHP 7.4) properties in PropertyNormalizer and ObjectNormalizer stop using deprecated Doctrine persistence classes [Cache] Fix wrong classname in deprecation message Fix regex lookahead syntax in ApplicationTest Fixed syntax in comment [SecurityBundle][FirewallMap] Remove unused property [Messenger][AMQP] Use delivery_mode=2 by default [FrameworkBundle][DependencyInjection] Skip removed ids in the lint container command and its associated pass [SECURITY] Revert "AbstractAuthenticationListener.php error instead info. Rebase of #28462" [FrameworkBundle][Secrets] Hook configured local dotenv file [DI] Improve performance of processDefinition fix redis multi host dsn not recognized fix constructor argument type declaration Fix invalid Windows path normalization [Validator][ConstraintValidator] Safe fail on invalid timezones [DoctrineBridge] Fixed submitting invalid ids when using queries with limit [FrameworkBundle] Add info & example to auto_mapping config ...

* 5.0: (21 commits) fix merge CS [FrameworkBundle][ContainerLintCommand] Improve messages when the kernel or the container is not supported [Serializer] Skip uninitialized (PHP 7.4) properties in PropertyNormalizer and ObjectNormalizer stop using deprecated Doctrine persistence classes [Cache] Fix wrong classname in deprecation message Fix regex lookahead syntax in ApplicationTest Fixed syntax in comment [SecurityBundle][FirewallMap] Remove unused property [Messenger][AMQP] Use delivery_mode=2 by default [FrameworkBundle][DependencyInjection] Skip removed ids in the lint container command and its associated pass [SECURITY] Revert "AbstractAuthenticationListener.php error instead info. Rebase of #28462" [FrameworkBundle][Secrets] Hook configured local dotenv file [DI] Improve performance of processDefinition fix redis multi host dsn not recognized fix constructor argument type declaration Fix invalid Windows path normalization [Validator][ConstraintValidator] Safe fail on invalid timezones [DoctrineBridge] Fixed submitting invalid ids when using queries with limit [FrameworkBundle] Add info & example to auto_mapping config ...

…nfo. Rebase of symfony#28462" This reverts commit 867eb78.

* 4.4: (21 commits) fix merge CS [FrameworkBundle][ContainerLintCommand] Improve messages when the kernel or the container is not supported [Serializer] Skip uninitialized (PHP 7.4) properties in PropertyNormalizer and ObjectNormalizer stop using deprecated Doctrine persistence classes [Cache] Fix wrong classname in deprecation message Fix regex lookahead syntax in ApplicationTest Fixed syntax in comment [SecurityBundle][FirewallMap] Remove unused property [Messenger][AMQP] Use delivery_mode=2 by default [FrameworkBundle][DependencyInjection] Skip removed ids in the lint container command and its associated pass [SECURITY] Revert "AbstractAuthenticationListener.php error instead info. Rebase of symfony#28462" [FrameworkBundle][Secrets] Hook configured local dotenv file [DI] Improve performance of processDefinition fix redis multi host dsn not recognized fix constructor argument type declaration Fix invalid Windows path normalization [Validator][ConstraintValidator] Safe fail on invalid timezones [DoctrineBridge] Fixed submitting invalid ids when using queries with limit [FrameworkBundle] Add info & example to auto_mapping config ...

* 5.0: (21 commits) fix merge CS [FrameworkBundle][ContainerLintCommand] Improve messages when the kernel or the container is not supported [Serializer] Skip uninitialized (PHP 7.4) properties in PropertyNormalizer and ObjectNormalizer stop using deprecated Doctrine persistence classes [Cache] Fix wrong classname in deprecation message Fix regex lookahead syntax in ApplicationTest Fixed syntax in comment [SecurityBundle][FirewallMap] Remove unused property [Messenger][AMQP] Use delivery_mode=2 by default [FrameworkBundle][DependencyInjection] Skip removed ids in the lint container command and its associated pass [SECURITY] Revert "AbstractAuthenticationListener.php error instead info. Rebase of symfony#28462" [FrameworkBundle][Secrets] Hook configured local dotenv file [DI] Improve performance of processDefinition fix redis multi host dsn not recognized fix constructor argument type declaration Fix invalid Windows path normalization [Validator][ConstraintValidator] Safe fail on invalid timezones [DoctrineBridge] Fixed submitting invalid ids when using queries with limit [FrameworkBundle] Add info & example to auto_mapping config ...

carsonbot added Status: Needs Review Security Bug labels Sep 13, 2018

Warxcell added 2 commits September 14, 2018 01:14

Update AbstractAuthenticationListener.php

c22ff3a

Use Symfony\Component\Security\Core\Exception\AuthenticationServiceException to determine logging level

Update AbstractAuthenticationListener.php

86cf04f

Fix coding standarts

nicolas-grekas added this to the 3.4 milestone Sep 18, 2018

fabpot added the Help wanted Issues and PRs which are looking for volunteers to complete them. label Mar 4, 2019

berezuev added a commit to berezuev/symfony that referenced this pull request May 20, 2019

rebase symfony#28462 [SECURITY] AbstractAuthenticationListener.php er…

eff7d2e

…ror instead info.

berezuev mentioned this pull request May 20, 2019

[SECURITY] AbstractAuthenticationListener.php error instead info. Rebase of #28462 #31554

Merged

fabpot closed this Jul 8, 2019

berezuev added a commit to berezuev/symfony that referenced this pull request Jul 8, 2019

[SECURITY] AbstractAuthenticationListener.php error instead info. Reb…

5c8fdb1

…ase of symfony#28462

berezuev added a commit to berezuev/symfony that referenced this pull request Jul 8, 2019

[SECURITY] AbstractAuthenticationListener.php error instead info. Reb…

867eb78

…ase of symfony#28462

This was referenced Nov 12, 2019

Release v4.4.0-BETA1 #34338

Merged

Release v5.0.0-BETA1 #34339

Merged

Fl0ux mentioned this pull request Dec 5, 2019

Failed login attempts are logged as error #34836

Closed

MolloKhan added a commit to MolloKhan/symfony that referenced this pull request Dec 12, 2019

[SECURITY] Revert "AbstractAuthenticationListener.php error instead i…

94d5cc9

…nfo. Rebase of symfony#28462" This reverts commit 867eb78.

nicolas-grekas pushed a commit to MolloKhan/symfony that referenced this pull request Dec 13, 2019

[SECURITY] Revert "AbstractAuthenticationListener.php error instead i…

9d306f9

…nfo. Rebase of symfony#28462" This reverts commit 867eb78.

raneomik pushed a commit to raneomik/symfony that referenced this pull request Dec 16, 2019

[SECURITY] Revert "AbstractAuthenticationListener.php error instead i…

3daebf2

…nfo. Rebase of symfony#28462" This reverts commit 867eb78.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[SECURITY] AbstractAuthenticationListener.php error instead info. #28462

[SECURITY] AbstractAuthenticationListener.php error instead info. #28462

Warxcell commented Sep 13, 2018 •

edited

Loading

jvasseur commented Sep 13, 2018

Warxcell commented Sep 13, 2018 •

edited

Loading

jvasseur commented Sep 13, 2018

Warxcell commented Sep 13, 2018 •

edited

Loading

linaori commented Sep 14, 2018

nicolas-grekas commented Sep 18, 2018

linaori commented Sep 18, 2018

Warxcell commented Sep 19, 2018

nicolas-grekas commented Oct 20, 2018

linaori commented Oct 21, 2018

Warxcell commented Nov 1, 2018

fabpot commented Mar 25, 2019

linaori commented Mar 25, 2019 •

edited

Loading

javiereguiluz commented Mar 25, 2019

curry684 commented Apr 6, 2019 •

edited

Loading

nicolas-grekas commented Apr 7, 2019

Fl0ux commented Dec 5, 2019

Warxcell commented Dec 5, 2019

nicolas-grekas commented Dec 5, 2019

Fl0ux commented Dec 5, 2019

Warxcell commented Dec 5, 2019 •

edited

Loading

[SECURITY] AbstractAuthenticationListener.php error instead info. #28462

[SECURITY] AbstractAuthenticationListener.php error instead info. #28462

Conversation

Warxcell commented Sep 13, 2018 • edited Loading

jvasseur commented Sep 13, 2018

Warxcell commented Sep 13, 2018 • edited Loading

jvasseur commented Sep 13, 2018

Warxcell commented Sep 13, 2018 • edited Loading

linaori commented Sep 14, 2018

UserAuthenticationProvider

DaoAuthenticationProvider

DigestAuthenticationListener

UnsupportedUserException

Final conclusion

nicolas-grekas commented Sep 18, 2018

linaori commented Sep 18, 2018

Warxcell commented Sep 19, 2018

nicolas-grekas commented Oct 20, 2018

linaori commented Oct 21, 2018

Warxcell commented Nov 1, 2018

fabpot commented Mar 25, 2019

linaori commented Mar 25, 2019 • edited Loading

javiereguiluz commented Mar 25, 2019

curry684 commented Apr 6, 2019 • edited Loading

nicolas-grekas commented Apr 7, 2019

Fl0ux commented Dec 5, 2019

Warxcell commented Dec 5, 2019

nicolas-grekas commented Dec 5, 2019

Fl0ux commented Dec 5, 2019

Warxcell commented Dec 5, 2019 • edited Loading

Warxcell commented Sep 13, 2018 •

edited

Loading

Warxcell commented Sep 13, 2018 •

edited

Loading

Warxcell commented Sep 13, 2018 •

edited

Loading

`UserAuthenticationProvider`

`DaoAuthenticationProvider`

`DigestAuthenticationListener`

`UnsupportedUserException`

linaori commented Mar 25, 2019 •

edited

Loading

curry684 commented Apr 6, 2019 •

edited

Loading

Warxcell commented Dec 5, 2019 •

edited

Loading