By: Stroe Marian user 03 Apr 2020 at 3:54 a.m. CDT

5 Responses
Stroe Marian gravatar
I have build an openID connector for GSuite , follow the docs here https://gluu.org/docs/gluu-server/authn-guide/inbound-oauth-passport/ When I try to connect with external provider , i obtain an error OOPS An unexpected error has occured at null Failed to authenticate. In passport.log : 2020-04-03T08:39:55.603Z [VERBOSE] getConfiguration called 2020-04-03T08:39:55.817Z [INFO] getConfiguration. Passport configs received 2020-04-03T08:39:55.819Z [INFO] Configuration data received 2020-04-03T08:39:55.820Z [INFO] Configuration data has been parsed 2020-04-03T08:40:19.911Z [VERBOSE] Issuing token 2020-04-03T08:40:19.913Z [INFO] ::1 - GET /passport/token HTTP/1.1 200 201 - 2.111 ms 2020-04-03T08:40:19.943Z [VERBOSE] Validating token 2020-04-03T08:40:19.945Z [VERBOSE] Authenticating request against gg 2020-04-03T08:40:19.947Z [INFO] ::1 - GET /passport/auth/gg/eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJqd3QiOiI3YzA3ZDdhYS1mMmQxLTRlNDctOTk4OC03MmQzZjgzMTMxNDEiLCJpYXQiOjE1ODU5MDMyMTksImV4cCI6MTU4NTkwMzMzOX0.d6Ekzk-_Q2qEwb_9xtP1Hhokwu2MC9_hKZ3d_yLBJxM HTTP/1.1 302 0 - 8.878 ms 2020-04-03T08:40:38.662Z [VERBOSE] Authenticating request against gg 2020-04-03T08:40:38.989Z [INFO] Applying mapping 'google' to profile 2020-04-03T08:40:38.990Z [DEBUG] Resulting profile data is { "provider": "gg", "uid": "112829789211616413082", "mail": "xxxxxxxxxxxxx@xxxxx.xx", "cn": "Marian Stroe", "displayName": "Marian Stroe", "givenName": "Marian", "sn": "Stroe" } 2020-04-03T08:40:38.990Z [INFO] User 112829789211616413082 authenticated with provider gg 2020-04-03T08:40:38.998Z [DEBUG] Sending user data eyJhbGciOiJSUzUxMiIsInR5cCI6IkpXVCIsImtpZCI6ImM1MGJkMzBjLWZjNGQtNDRiNi1iNmM5LTcwOWZjZWUxY2I4Zl9zaWdfcnM1MTIifQ.eyJpc3MiOiJodHRwczovL2dsdXUudW5pYnVjLnJvL294YXV0aC9wb3N0bG9naW4uaHRtIiwic3ViIjoiMTEyODI5Nzg5MjExNjE2NDEzMDgyIiwiYXVkIjoiMTUwMi42OTViNDM4Zi0xYmMwLTQ3MmUtOTYzYS04NTNkMmViYzZmZWYiLCJqdGkiOiJkY2M3OGRiZS03NDUwLTQ5YzEtODliNS0zZTM1NDQ4Y2NjMTEiLCJleHAiOjE1ODU5MDMyNjguOTkxLCJpYXQiOjE1ODU5MDMyMzg5OTEsImRhdGEiOiJrdFhpYVVrYTEzRzFxRGYrTlN3QWZLdFJuM0NnODJOOHJGclA3ZUFGK09mb3dtK2loMVdpdWlJT3dTQzBjWUlXNkVaRHNhMkVrakptcmFicXZvb0JORWJPTVBRaHlGblVmdzJzTVZCZ2lvL1VPYUpOUm1XYVNiUlRybzlWUENCTms3dXVaUmZkdE5CVkNsdjFrSWdxWVVjd1ltNkFZTStsYzNwV3RvOUZHVDhwR0JrbU8wZ2VBU1dZTGxydzluOFFnSzJUMzJRTVN1bVNSZVVmZTIzb2w5N1VMWXlQeUtZVWJJSERyN1R4UTI1ZldTY0Rsc0RJS0E9PSJ9.JcUi3e7viruy5Pn-FxHxVepDFKGMHKinR3hf89wCZUfO9pHjQ6tNqHuKVioA_AefTg-i1akEYqEoxUWDwZ7wWSqc_IBgwP8nnOFL0ddFP4DMFkn2JERk3aYFCiiiKXEWlRy2uSHgk0fHssKH5H29GAr8sGR-5oLoXGipeYbOpHLGBSb4Y5jIQGV7RDmR808_ed2d6vL9SIL3Op23U5VnIwekaBKXDBV8TQQikIYrAaT2MArRrg0xKZg7Y_R9hLNyaTTFem7pdy-CntQI7RLuD8Sz27nL4Q19Ln6XXzzAUVbwnZV_71WLYkXI2PQB8a72EAaxCUJRiQY32pDrkpcJQQ to: https://server_name/oxauth/postlogin.htm 2020-04-03T08:40:39.001Z [INFO] ::1 - GET /passport/auth/gg/callback?code=4%2FyQG9Qm2xXv7OHKKcLY9mHsJgrppqI9vmQYrURFBIioXA4RRJt-2wLfpSUSmLZ9OIIk0yHzbXXMHIIStL7NfEu_o&scope=email+profile+https%3A%2F%2Fwww.googleapis.com%2Fauth%2Fuserinfo.profile+openid+https%3A%2F%2Fwww.googleapis.com%2Fauth%2Fuserinfo.email&authuser=0&hd=it.unibuc.ro&prompt=none HTTP/1.1 200 1626 - 338.611 ms ( I replace by hand the email address and server name in log ) It supposed to update the local ldap with this user , no ?

By Jose Gonzalez staff 08 Apr 2020 at 1:29 p.m. CDT

Jose Gonzalez gravatar
please provide a relevant portion of `/opt/gluu/jetty/oxauth/logs/oxauth_script.log`

By Stroe Marian user 08 Apr 2020 at 1:56 p.m. CDT

Stroe Marian gravatar
Thanks for your reply Here is requested log : 2020-04-08 21:53:48,236 INFO [qtp353842779-126156] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getExtraParametersForStep called 2020-04-08 21:53:52,311 INFO [qtp353842779-126873] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. authenticate for step 1 called 2020-04-08 21:53:52,312 INFO [qtp353842779-126873] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. authenticate for step 1. Basic authentication detected 2020-04-08 21:53:52,339 INFO [qtp353842779-126873] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. authenticate for step 1. Basic authentication returned: True 2020-04-08 21:53:52,341 INFO [qtp353842779-126873] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getExtraParametersForStep called 2020-04-08 21:53:52,342 INFO [qtp353842779-126873] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getCountAuthenticationSteps called 2020-04-08 21:53:52,346 INFO [qtp353842779-126873] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getExtraParametersForStep called 2020-04-08 21:54:19,925 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getPageForStep called 2020-04-08 21:54:19,968 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. prepareForStep called 1 2020-04-08 21:54:19,970 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. parseAllProviders. Adding providers 2020-04-08 21:54:20,513 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. parseProviderConfigs. Configured providers: 2020-04-08 21:54:20,514 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - {u'gg': {'requestForEmail': False, 'displayName': u'GSuite', 'emailLinkingSafe': False, 'type': u'oauth', 'logo_img': u'/oxauth/ext/resources/img/gsuite.png', 'saml': False}} 2020-04-08 21:54:20,516 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. prepareForStep. A page to manually select an identity provider will be shown 2020-04-08 21:54:20,517 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getExtraParametersForStep called 2020-04-08 21:54:22,880 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. authenticate for step 1 called 2020-04-08 21:54:22,883 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. authenticate for step 1. Retrying step 1 2020-04-08 21:54:22,901 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getExtraParametersForStep called 2020-04-08 21:54:22,902 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getCountAuthenticationSteps called 2020-04-08 21:54:22,907 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getPageForStep called 2020-04-08 21:54:22,908 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getExtraParametersForStep called 2020-04-08 21:54:22,944 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. prepareForStep called 1 2020-04-08 21:54:22,946 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. parseAllProviders. Adding providers 2020-04-08 21:54:23,505 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. parseProviderConfigs. Configured providers: 2020-04-08 21:54:23,505 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - {u'gg': {'requestForEmail': False, 'displayName': u'GSuite', 'emailLinkingSafe': False, 'type': u'oauth', 'logo_img': u'/oxauth/ext/resources/img/gsuite.png', 'saml': False}} 2020-04-08 21:54:23,521 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getPassportRedirectUrl. Obtaining token from passport at https://gluu.unibuc.ro/passport/token 2020-04-08 21:54:23,613 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getPassportRedirectUrl. Response was 200 2020-04-08 21:54:23,618 INFO [qtp353842779-126404] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. getExtraParametersForStep called 2020-04-08 21:54:24,467 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. authenticate for step 1 called 2020-04-08 21:54:24,468 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. authenticate for step 1. JWT user profile token found 2020-04-08 21:54:24,469 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. validSignature. Checking JWT token signature 2020-04-08 21:54:24,474 INFO [qtp353842779-126405] [org.gluu.service.PythonService$PythonLoggerOutputStream] (PythonService.java:240) - Passport. validSignature. Validation result was True root@gluu:/opt/gluu-server/opt/gluu/jetty/oxauth/logs#

By Jose Gonzalez staff 08 Apr 2020 at 2:22 p.m. CDT

Jose Gonzalez gravatar
I think your log is incomplete. After a successful JWT signature validation (last line shown) there have to be more log traces.... It cannot simply stop here: https://github.com/GluuFederation/oxAuth/blob/version_4.1.0/Server/integrations/passport/PassportExternalAuthenticator.py#L92

By Stroe Marian user 08 Apr 2020 at 2:51 p.m. CDT

Stroe Marian gravatar
No , I copied all the log .... no another raw And the Oops page came, no user added in database

By Jose Gonzalez staff 09 Apr 2020 at 11:03 a.m. CDT

Jose Gonzalez gravatar
It's impossible the flow simply gets interrupted in the middle of script execution leaving no traces. Since Gluu is fully open source I invite you to explore the code and find a solution on your own. We can't provide more assistance here. Another option for you is to purchase a membership to get a deeper insight into this problem.