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.

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

Non-uid primary key resulting 502 #1600

Open
mzico opened this issue Dec 6, 2021 · 8 comments
Open

Non-uid primary key resulting 502 #1600

mzico opened this issue Dec 6, 2021 · 8 comments
Assignees
Labels
bug bug in code
Milestone

Comments

@mzico
Copy link
Contributor

mzico commented Dec 6, 2021

I am testing Brute Force Protection, it's working perfectly when primary key is "UID".

Testing with "Email" is not actually doing what it suppose to do but resulting 502.

As for example: in this ( https://www.youtube.com/watch?v=nK0nhGtmrrQ&ab_channel=MohibZico ) recorded screencast....

  • For UID case, After 3 consecutive failed login the "Brute Force Protection" enabled and working as it should be.
  • For EmailAddress, after 2nd failed login, oxAuth throwing 502.

oxauth.log showing below:

021-12-06 05:09:19,235 TRACE [oxAuthScheduler_Worker-5] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.ConfigurationEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 270174041
2021-12-06 05:09:19,235 DEBUG [oxAuthScheduler_Worker-5] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:19,237 TRACE [Thread-2203] [org.gluu.oxauth.model.config.ConfigurationFactory] (ConfigurationFactory.java:259) - LDAP revision: 11, server revision:11
2021-12-06 05:09:19,241 DEBUG [oxAuthScheduler_Worker-4] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:19,241 TRACE [oxAuthScheduler_Worker-4] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.LoggerUpdateEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 1152917210
2021-12-06 05:09:19,241 DEBUG [oxAuthScheduler_Worker-4] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:19,261 INFO  [Thread-2204] [org.gluu.service.logger.LoggerService] (LoggerService.java:205) - Updated log level of '139' loggers to TRACE
2021-12-06 05:09:19,289 DEBUG [oxAuthScheduler_Worker-2] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:19,290 TRACE [oxAuthScheduler_Worker-2] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.oxauth.service.cdi.event.AuthConfigurationEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 1721751672
2021-12-06 05:09:19,303 DEBUG [oxAuthScheduler_Worker-2] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:19,313 TRACE [Thread-2207] [org.gluu.oxauth.service.AppInitializer] (AppInitializer.java:307) - Attempting to use persistenceEntryManager: org.gluu.persist.ldap.operation.impl.LdapOperationServiceImpl@18887028


2021-12-06 05:09:19,820 DEBUG [Thread-2205] [org.gluu.service.cache.NativePersistenceCacheProvider] (NativePersistenceCacheProvider.java:282) - Start NATIVE_PERSISTENCE clean up
2021-12-06 05:09:19,823 DEBUG [Thread-2205] [org.gluu.service.cache.NativePersistenceCacheProvider] (NativePersistenceCacheProvider.java:289) - End NATIVE_PERSISTENCE clean up, items removed: 1
2021-12-06 05:09:25,111 DEBUG [oxAuthScheduler_Worker-3] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:25,111 TRACE [oxAuthScheduler_Worker-3] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.UpdateScriptEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 310503721
2021-12-06 05:09:25,126 DEBUG [oxAuthScheduler_Worker-3] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:27,825 TRACE [qtp536765369-20] [org.gluu.oxauth.uma.service.UmaValidationService] (UmaValidationService.java:110) - Validate authorization: Bearer 90379a6b-2678-43ee-8746-a4ecdb38dfee
2021-12-06 05:09:27,825 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key '75c65c4503408a3dcca81793fd65abf9b253a545184480f475c4f585a4a434ab'
2021-12-06 05:09:27,826 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key '75c65c4503408a3dcca81793fd65abf9b253a545184480f475c4f585a4a434ab': 'null'
2021-12-06 05:09:27,829 DEBUG [qtp536765369-20] [org.gluu.oxauth.service.common.UserService] (UserService.java:81) - Getting user information from LDAP: userId = null
2021-12-06 05:09:27,829 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=1501.5bcd415e-2993-4e1f-b863-ed9835ba4460,ou=clients,o=gluu'
2021-12-06 05:09:27,830 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=1501.5bcd415e-2993-4e1f-b863-ed9835ba4460,ou=clients,o=gluu': 'null'
2021-12-06 05:09:27,830 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:61) - Key not in cache. Searching value via load function, key: 'inum=1501.5bcd415e-2993-4e1f-b863-ed9835ba4460,ou=clients,o=gluu'
2021-12-06 05:09:27,832 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'inum=1501.5bcd415e-2993-4e1f-b863-ed9835ba4460,ou=clients,o=gluu': 'DeletableEntity{expirationDate=null, deletable=null} BaseEntry [dn=inum=1501.5bcd415e-2993-4e1f-b863-ed9835ba4460,ou=clients,o=gluu]'
2021-12-06 05:09:27,832 DEBUG [qtp536765369-20] [org.gluu.oxauth.service.ClientService] (ClientService.java:135) - Found 1 entries for client id = 1501.5bcd415e-2993-4e1f-b863-ed9835ba4460
2021-12-06 05:09:27,840 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'inum=1502.738005cd-e4ff-461e-87d6-2621c2ae5464,ou=clients,o=gluu'
2021-12-06 05:09:27,840 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'inum=1502.738005cd-e4ff-461e-87d6-2621c2ae5464,ou=clients,o=gluu': 'null'
2021-12-06 05:09:27,840 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:61) - Key not in cache. Searching value via load function, key: 'inum=1502.738005cd-e4ff-461e-87d6-2621c2ae5464,ou=clients,o=gluu'
2021-12-06 05:09:27,842 TRACE [qtp536765369-20] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'inum=1502.738005cd-e4ff-461e-87d6-2621c2ae5464,ou=clients,o=gluu': 'DeletableEntity{expirationDate=null, deletable=null} BaseEntry [dn=inum=1502.738005cd-e4ff-461e-87d6-2621c2ae5464,ou=clients,o=gluu]'
2021-12-06 05:09:27,842 DEBUG [qtp536765369-20] [org.gluu.oxauth.service.ClientService] (ClientService.java:135) - Found 1 entries for client id = 1502.738005cd-e4ff-461e-87d6-2621c2ae5464
2021-12-06 05:09:27,843 TRACE [qtp536765369-20] [gluu.oxauth.uma.ws.rs.UmaRptIntrospectionWS] (UmaRptIntrospectionWS.java:133) - Canceled changes made by external RPT Claims script since method returned `false`.
2021-12-06 05:09:34,240 DEBUG [oxAuthScheduler_Worker-5] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:34,241 TRACE [oxAuthScheduler_Worker-5] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.LoggerUpdateEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 142281225
2021-12-06 05:09:34,241 DEBUG [oxAuthScheduler_Worker-5] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:34,261 INFO  [Thread-2208] [org.gluu.service.logger.LoggerService] (LoggerService.java:205) - Updated log level of '139' loggers to TRACE
2021-12-06 05:09:49,235 DEBUG [oxAuthScheduler_Worker-4] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:49,235 TRACE [oxAuthScheduler_Worker-4] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.ConfigurationEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 1922444094
2021-12-06 05:09:49,235 DEBUG [oxAuthScheduler_Worker-4] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:49,238 TRACE [Thread-2209] [org.gluu.oxauth.model.config.ConfigurationFactory] (ConfigurationFactory.java:259) - LDAP revision: 11, server revision:11
2021-12-06 05:09:49,240 DEBUG [oxAuthScheduler_Worker-1] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:49,240 TRACE [oxAuthScheduler_Worker-1] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.LoggerUpdateEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 786019613
2021-12-06 05:09:49,240 DEBUG [oxAuthScheduler_Worker-1] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:49,251 DEBUG [oxAuthScheduler_Worker-2] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:49,251 TRACE [oxAuthScheduler_Worker-2] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.LdapStatusEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 1620600900
2021-12-06 05:09:49,252 DEBUG [oxAuthScheduler_Worker-2] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:49,260 INFO  [Thread-2210] [org.gluu.service.logger.LoggerService] (LoggerService.java:205) - Updated log level of '139' loggers to TRACE
2021-12-06 05:09:49,261 DEBUG [oxAuthScheduler_Worker-3] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:49,261 TRACE [oxAuthScheduler_Worker-3] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.CleanerEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 322223607
2021-12-06 05:09:49,261 DEBUG [oxAuthScheduler_Worker-3] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:49,271 DEBUG [oxAuthScheduler_Worker-5] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:49,271 TRACE [oxAuthScheduler_Worker-5] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.oxauth.service.cdi.event.KeyGenerationEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 414569083
2021-12-06 05:09:49,271 DEBUG [oxAuthScheduler_Worker-5] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:49,287 DEBUG [oxAuthScheduler_Worker-4] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:49,287 DEBUG [oxAuthScheduler_Worker-1] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:49,287 TRACE [oxAuthScheduler_Worker-4] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.oxauth.service.cdi.event.StatEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 2811783
2021-12-06 05:09:49,287 TRACE [oxAuthScheduler_Worker-1] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.oxauth.service.cdi.event.AuthConfigurationEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 957716173
2021-12-06 05:09:49,288 DEBUG [oxAuthScheduler_Worker-4] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:49,289 DEBUG [oxAuthScheduler_Worker-1] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:09:49,289 TRACE [Thread-2216] [org.gluu.oxauth.service.AppInitializer] (AppInitializer.java:307) - Attempting to use persistenceEntryManager: org.gluu.persist.ldap.operation.impl.LdapOperationServiceImpl@18887028
2021-12-06 05:09:55,111 DEBUG [oxAuthScheduler_Worker-2] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:09:55,111 TRACE [oxAuthScheduler_Worker-2] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.UpdateScriptEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 1159332448
2021-12-06 05:09:55,127 DEBUG [oxAuthScheduler_Worker-2] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:10:03,582 TRACE [qtp536765369-14] [org.gluu.oxauth.service.CookieService] (CookieService.java:156) - Found cookie: 'df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32'
2021-12-06 05:10:03,582 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'oxId=df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32,ou=sessions,o=gluu'
2021-12-06 05:10:03,582 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'oxId=df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32,ou=sessions,o=gluu': 'null'
2021-12-06 05:10:03,585 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32,ou=sessions,o=gluu': 'SessionId {dn='oxId=df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32,ou=sessions,o=gluu', id='df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32', outsideSid='1b259a7f-ef63-460d-bdfa-9047620219b2', lastUsedAt=Mon Dec 06 05:09:03 UTC 2021, userDn='null', authenticationTime=Mon Dec 06 05:08:47 UTC 2021, state=unauthenticated, expirationDate=Mon Dec 06 05:10:47 UTC 2021, sessionState='5cf40fee6aea0939db68bfb73ca052c6cbf3a2812ae751ac3c5a874f0da7d6f3.c378f7a7-57d5-4ed1-be0f-d60e098ab3dc', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.2d07f520-6242-4743-b294-7665afdac4d5=false}}, sessionAttributes={auth_step=1, acr=auth_ldap_server, remote_ip=118.179.84.52, auth_external_attributes=null, opbs=bd983425-8652-4f18-8db4-27b9e0e4d2b7, scope=openid profile email user_name, acr_values=auth_ldap_server, response_type=code, redirect_uri=https://allhands43.gluu.org/identity/authcode.htm, state=c51764bc-2a60-4bc9-aff9-ea77f60bb05c, nonce=e7b75939-549b-4110-910c-ced69cefa709, client_id=1001.2d07f520-6242-4743-b294-7665afdac4d5}, persisted=false}'
2021-12-06 05:10:03,586 TRACE [qtp536765369-14] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:821) - Try to get session by id: df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32 ...
2021-12-06 05:10:03,586 TRACE [qtp536765369-14] [org.gluu.oxauth.service.SessionIdService] (SessionIdService.java:823) - Session dn: oxId=df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32,ou=sessions,o=gluu
2021-12-06 05:10:03,590 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32,ou=sessions,o=gluu': 'SessionId {dn='oxId=df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32,ou=sessions,o=gluu', id='df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32', outsideSid='1b259a7f-ef63-460d-bdfa-9047620219b2', lastUsedAt=Mon Dec 06 05:10:03 UTC 2021, userDn='null', authenticationTime=Mon Dec 06 05:08:47 UTC 2021, state=unauthenticated, expirationDate=Mon Dec 06 05:10:47 UTC 2021, sessionState='5cf40fee6aea0939db68bfb73ca052c6cbf3a2812ae751ac3c5a874f0da7d6f3.c378f7a7-57d5-4ed1-be0f-d60e098ab3dc', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.2d07f520-6242-4743-b294-7665afdac4d5=false}}, sessionAttributes={auth_step=1, acr=auth_ldap_server, remote_ip=118.179.84.52, auth_external_attributes=null, opbs=bd983425-8652-4f18-8db4-27b9e0e4d2b7, scope=openid profile email user_name, acr_values=auth_ldap_server, response_type=code, redirect_uri=https://allhands43.gluu.org/identity/authcode.htm, state=c51764bc-2a60-4bc9-aff9-ea77f60bb05c, nonce=e7b75939-549b-4110-910c-ced69cefa709, client_id=1001.2d07f520-6242-4743-b294-7665afdac4d5}, persisted=true}'
2021-12-06 05:10:03,590 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'user_zico@gluu.org'
2021-12-06 05:10:03,591 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'user_zico@gluu.org': 'null'
2021-12-06 05:10:03,592 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'user_zico@gluu.org': 'org.gluu.model.security.protect.AuthenticationAttemptList@2e65b79e'
2021-12-06 05:10:03,596 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:37) - Request data, key 'user_zico@gluu.org'
2021-12-06 05:10:03,597 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:39) - Loaded data, key 'user_zico@gluu.org': 'org.gluu.model.security.protect.AuthenticationAttemptList@76a42b68'
2021-12-06 05:10:03,597 DEBUG [qtp536765369-14] [org.gluu.service.security.protect.AuthenticationProtectionService] (AuthenticationProtectionService.java:97) - Allowing current login attempt without delay
2021-12-06 05:10:03,597 TRACE [qtp536765369-14] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:338) - #########################################################################
2021-12-06 05:10:03,597 TRACE [qtp536765369-14] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:339) - ++++++++++++++++++++++++++++++++++++++++++CURRENT ACR:auth_ldap_server
2021-12-06 05:10:03,598 TRACE [qtp536765369-14] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:340) - ++++++++++++++++++++++++++++++++++++++++++CURRENT STEP:1
2021-12-06 05:10:03,602 TRACE [qtp536765369-14] [org.gluu.service.BaseCacheService] (BaseCacheService.java:84) - Put data, key 'oxId=df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32,ou=sessions,o=gluu': 'SessionId {dn='oxId=df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32,ou=sessions,o=gluu', id='df2d4a6b-77fe-48ec-9fab-a7aa78eb8e32', outsideSid='1b259a7f-ef63-460d-bdfa-9047620219b2', lastUsedAt=Mon Dec 06 05:10:03 UTC 2021, userDn='null', authenticationTime=Mon Dec 06 05:08:47 UTC 2021, state=unauthenticated, expirationDate=Mon Dec 06 05:10:47 UTC 2021, sessionState='5cf40fee6aea0939db68bfb73ca052c6cbf3a2812ae751ac3c5a874f0da7d6f3.c378f7a7-57d5-4ed1-be0f-d60e098ab3dc', permissionGranted=null, isJwt=false, jwt=null, permissionGrantedMap=SessionIdAccessMap{permissionGranted={1001.2d07f520-6242-4743-b294-7665afdac4d5=false}}, sessionAttributes={auth_step=1, acr=auth_ldap_server, remote_ip=118.179.84.52, auth_external_attributes=null, opbs=bd983425-8652-4f18-8db4-27b9e0e4d2b7, scope=openid profile email user_name, acr_values=auth_ldap_server, response_type=code, redirect_uri=https://allhands43.gluu.org/identity/authcode.htm, state=c51764bc-2a60-4bc9-aff9-ea77f60bb05c, nonce=e7b75939-549b-4110-910c-ced69cefa709, client_id=1001.2d07f520-6242-4743-b294-7665afdac4d5}, persisted=true}'
2021-12-06 05:10:03,602 INFO  [qtp536765369-14] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:225) - Authentication failed for 'zico@gluu.org'
2021-12-06 05:10:04,240 DEBUG [oxAuthScheduler_Worker-3] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:53) - Bound request started
2021-12-06 05:10:04,240 TRACE [oxAuthScheduler_Worker-3] [org.gluu.service.timer.TimerJob] (TimerJob.java:35) - Fire timer event [org.gluu.service.cdi.event.LoggerUpdateEvent] with qualifiers [@org.gluu.service.cdi.event.Scheduled()] from instance 2139595066
2021-12-06 05:10:04,241 DEBUG [oxAuthScheduler_Worker-3] [org.gluu.service.timer.RequestJobListener] (RequestJobListener.java:63) - Bound request ended
2021-12-06 05:10:04,261 INFO  [Thread-2217] [org.gluu.service.logger.LoggerService] (LoggerService.java:205) - Updated log level of '139' loggers to TRACE
@mzico mzico added the bug bug in code label Dec 6, 2021
@mzico mzico added this to the 4.3.1 milestone Dec 6, 2021
@yurem
Copy link
Contributor

yurem commented Dec 7, 2021

I can't reproduce this issue. It's more likely network issue. I so because:

A 502 Bad Gateway Error means that the web server you've connected to is acting as a proxy for relaying information from another server, but it has gotten a bad response from that other server. It's called a 502 error because that's the HTTP status code that the webserver uses to describe that kind of error.

@mzico
Copy link
Contributor Author

mzico commented Dec 7, 2021

@MohitMaliFtechiz : can you please check if it's reproduce able from your network?

@MohitMaliFtechiz
Copy link
Collaborator

@mzico ok i'll try to reproduce it

@MohitMaliFtechiz
Copy link
Collaborator

@yurem @mzico i am able to replicate the issue on my local vm. as @mzico said For EmailAddress, after 2nd failed login, oxAuth throwing 502 on oxauth config i set maximumAllowedAttemptsWithoutDelay=3 and change authentication primary key to email brute force enable after 2nd attempt and result to 502 error. however with primary key uid it works as it should be, the delay comes after 3 failed logins

@yurem
Copy link
Contributor

yurem commented Dec 10, 2021

@MohitMaliFtechiz Can you check if there are exceptions in the logs? Also, check apache logs, please. Did you checked login with email in new private session?

@yurem
Copy link
Contributor

yurem commented Dec 10, 2021

In my environment I get expected error messages without HTTP 502 error:

2021-12-10 19:43:52,333 DEBUG [qtp1966250569-16] [org.gluu.service.security.protect.AuthenticationProtectionService] (AuthenticationProtectionService.java:104) - Current login attempt requires delay: '2' seconds
2021-12-10 19:43:54,347 DEBUG [qtp1966250569-16] [org.gluu.service.security.protect.AuthenticationProtectionService] (AuthenticationProtectionService.java:104) - Current login attempt requires delay: '2' seconds
2021-12-10 19:43:56,354 INFO  [qtp1966250569-16] [org.gluu.oxauth.auth.Authenticator] (Authenticator.java:225) - Authentication failed for 'admin@u204.gluu.info'

@MohitMaliFtechiz
Copy link
Collaborator

primaykeyuid_oxauth.log
primaykeyemail_oxauth.log
apache_error.log
here are the apache and oxauth logs, there are some authentication exceptions caused by invalid credentials only which are ok as we are providing wrong credentials

@mzico
Copy link
Contributor Author

mzico commented Dec 19, 2021

@yurem : may be we can share an installation with you which is facing problem? Might be easier for you?

@shmorri shmorri modified the milestones: 4.3.1, 4.3.2 Feb 17, 2022
@MohitMaliFtechiz MohitMaliFtechiz modified the milestones: 4.3.2, 4.4.0 Apr 12, 2022
@shmorri shmorri modified the milestones: 4.4.0, 4.4.1 Apr 18, 2022
@shmorri shmorri modified the milestones: 4.4.1, 4.5 Jun 23, 2022
@shmorri shmorri modified the milestones: 4.5, 4.5.1 Nov 22, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug bug in code
Projects
None yet
Development

No branches or pull requests

4 participants