PAC4J - J2E - Facebook login - State parameter mismatch - But only after app restart or redeploy

Balázs Bakai

unread,

Sep 30, 2016, 11:57:54 AM9/30/16

to pac4j-users

Hi Pac4j Users!

Currently I am integrating Facebook in our JSF based Java EE 7 application with pac4j.

After application redeploy or server restart the first facebook login try is always wrong because of "State parameter mismatch" error.

After the first one, everything works fine with different bowsers and facebook accounts too.

I think the problem could be in somwwehere the pac4j init logic, beacuse it happens only after application restart and only the first try.

Could you help me?

The generated url, when the request fails:

http://localhost:8080/MY/callback?client_name=FacebookClient&code=AQC8fnMivb6hEXzLliBuXASFVgMDUP7pWJmLPQpbA0Tcpn6B70NCXCDwLpNPTUSy-JLmjH1tBzaU52MjQFQqaGlmFVW9Hx5-ezjhZ2Ge-DQXdn9NS-aerjRIJgNzjbvBhyIJ3fgW3kjwAp5-Oq4ylWjOmrQEzuzWpYzQxX40LsWhYzQIQOWwMWzG_TYobScxMNvBk5Ygipn2O2Q0WDB1JLkMNix2R1owXyuy_5q4rcvPTGb4fRibz8eoX79FA3CXJOjA-CkDGIwYy7RM4h74ncVAuVN6SYGEwc8p1vynCWUlTCdquSyzdoUOAjwSJIOs008I_U4re7I8Sablh7OmZA2u&state=a355b27a6e#_=_

Wildlfy appserver exception:

7:51:52,547 INFO [org.pac4j.core.config.ConfigBuilder] (default task-8) Build the configuration from factory: hu.et.util.security.Pac4JConfigFactory

17:51:52,556 ERROR [io.undertow.request] (default task-8) UT005023: Exception handling request to /MY/callback: org.pac4j.oauth.exception.OAuthCredentialsException: State parameter mismatch: session expired or possible threat of cross-site request forgery

at org.pac4j.oauth.client.BaseOAuth20StateClient.getOAuthCredentials(BaseOAuth20StateClient.java:69)

at org.pac4j.oauth.client.BaseOAuthClient.retrieveCredentials(BaseOAuthClient.java:135)

at org.pac4j.oauth.client.BaseOAuthClient.retrieveCredentials(BaseOAuthClient.java:33)

at org.pac4j.core.client.IndirectClient.getCredentials(IndirectClient.java:105)

at org.pac4j.core.engine.DefaultCallbackLogic.perform(DefaultCallbackLogic.java:77)

at org.pac4j.j2e.filter.CallbackFilter.internalFilter(CallbackFilter.java:62)

at org.pac4j.j2e.filter.AbstractConfigFilter.doFilter(AbstractConfigFilter.java:81)

at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)

at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)

at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)

at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)

at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)

at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)

at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)

at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)

at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)

at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)

at io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:53)

at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)

at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)

at io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:59)

at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)

at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)

at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)

at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)

at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)

at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)

at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)

at io.undertow.servlet.handlers.ServletInitialHandler.jrHandle(ServletInitialHandler.java)

at org.zeroturnaround.javarebel.integration.servlet.undertow.cbp.ServletInitialHandlerCBP.handleRequest(ServletInitialHandlerCBP.java:98)

at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:292)

at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)

at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)

at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)

at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)

at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)

at io.undertow.servlet.api.LegacyThreadSetupActionWrapper$1.call(LegacyThreadSetupActionWrapper.java:44)

at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)

at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)

at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)

at io.undertow.server.Connectors.executeRootHandler(Connectors.java:202)

at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:805)

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

at java.lang.Thread.run(Thread.java:745)

Jérôme LELEU

unread,

Sep 30, 2016, 12:39:57 PM9/30/16

to Balázs Bakai, pac4j-users

Hi,

I have never encountered this issue after a server restart. Tested with this demo for example: https://github.com/pac4j/j2e-pac4j-demo

Maybe JSF brings something special.

The internal behaviour is the following:

1) Before redirecting to Facebook for login, a state is generated and saved into the web session

2) Login occurs

3) When back to the web app, the state parameter in the request URL returned by Facebook is checked against the state saved into the web session and if they are different, you get this error

You should turn on DEBUG logs on org.pac4j to see what's going on.

Thanks.

Best regards,

Jérôme

--
You received this message because you are subscribed to the Google Groups "pac4j-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to pac4j-users+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Balázs Bakai

unread,

Sep 30, 2016, 6:44:26 PM9/30/16

to pac4j-users, bakai...@gmail.com

HI!

This is the debug log at the first time (after server restart) exception:

00:40:46,455 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: clients: FacebookClient

00:40:46,455 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: authorizers: securityHeaders

00:40:46,455 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: matchers: null

00:40:46,455 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) Boolean param: multiProfile: null

00:40:46,455 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: clientsFactory: null

00:40:46,455 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: isAjax: null

00:40:46,455 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: stateless: null

00:40:46,455 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: requireAnyRole: null

00:40:46,456 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: requireAllRoles: null

00:40:46,456 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: clientName: null

00:40:46,456 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: authorizerName: null

00:40:46,456 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: matcherName: null

00:40:46,460 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) === SECURITY ===

00:40:46,460 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) url: http://localhost:8080/MY/facebook-servlet/login

00:40:46,460 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) matchers: null

00:40:46,460 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) clients: FacebookClient

00:40:46,460 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) currentClients: [#FacebookClient# | name: FacebookClient | callbackUrl: http://localhost:8080/MY/callback?client_name=FacebookClient | callbackUrlResolver:

org.pac4j.core.http.DefaultCallbackUrlResolver@c39564c | ajaxRequestResolver: org.pac4j.core.http.DefaultAjaxRequestResolver@67a3517d |]

00:40:46,461 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) loadProfilesFromSession: true

00:40:46,461 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) profiles: []

00:40:46,461 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) Starting authentication

00:40:46,461 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) requestedUrl: http://localhost:8080/MY/facebook-servlet/login

00:40:46,472 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-7) authorizationUrl: https://www.facebook.com/v2.5/dialog/oauth?client_id=352677795074422&redirect_uri=http%3A%2F%2Flocalhost%3A8080%2FMY%2Fcallback

%3Fclient_name%3DFacebookClient&scope=user_birthday%2Cemail&state=3420d4aac5

00:40:46,605 INFO [org.pac4j.core.config.ConfigBuilder] (default task-8) Build the configuration from factory: hu.et.util.security.Pac4JConfigFactory

00:40:46,608 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-8) String param: defaultUrl: pages/home.jsf

00:40:46,608 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-8) Boolean param: multiProfile: true

00:40:46,608 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-8) Boolean param: renewSession: true

00:40:46,608 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-8) String param: clientsFactory: null

00:40:46,609 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-8) === CALLBACK ===

00:40:46,609 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-8) client: #FacebookClient# | name: FacebookClient | callbackUrl: http://localhost:8080/MY/callback?client_name=FacebookClient | callbackUrlResolver:

org.pac4j.core.http.DefaultCallbackUrlResolver@4dcf7b33 | ajaxRequestResolver: org.pac4j.core.http.DefaultAjaxRequestResolver@4bd7994d |

00:40:46,611 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-8) sessionState: 1594598229 / stateParameter: 3420d4aac5

00:40:46,613 ERROR [io.undertow.request] (default task-8) UT005023: Exception handling request to /MY/callback: org.pac4j.oauth.exception.OAuthCredentialsException: State parameter mismatch: session expired or possible threat of cross-

and this is the good case after this first time issue:

00:41:29,677 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-15) === SECURITY ===

00:41:29,677 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-15) url: http://localhost:8080/MY/facebook-servlet/login

00:41:29,678 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-15) matchers: null

00:41:29,678 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-15) clients: FacebookClient

00:41:29,678 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-15) currentClients: [#FacebookClient# | name: FacebookClient | callbackUrl: http://localhost:8080/MY/callback?client_name=FacebookClient |

callbackUrlResolver: org.pac4j.core.http.DefaultCallbackUrlResolver@c39564c | ajaxRequestResolver: org.pac4j.core.http.DefaultAjaxRequestResolver@67a3517d |]

00:41:29,678 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-15) loadProfilesFromSession: true

00:41:29,678 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-15) profiles: []

00:41:29,678 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-15) Starting authentication

00:41:29,678 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-15) requestedUrl: http://localhost:8080/MY/facebook-servlet/login

00:41:29,679 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-15) authorizationUrl: https://www.facebook.com/v2.5/dialog/oauth?client_id=352677795074422&redirect_uri=http%3A%2F%2Flocalhost%3A8080%2FMY%2Fcallback

%3Fclient_name%3DFacebookClient&scope=user_birthday%2Cemail&state=d15a80f327

00:41:29,783 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-16) === CALLBACK ===

00:41:29,784 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-16) client: #FacebookClient# | name: FacebookClient | callbackUrl: http://localhost:8080/MY/callback?client_name=FacebookClient | callbackUrlResolver:

org.pac4j.core.http.DefaultCallbackUrlResolver@4dcf7b33 | ajaxRequestResolver: org.pac4j.core.http.DefaultAjaxRequestResolver@4bd7994d |

00:41:29,784 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-16) sessionState: d15a80f327 / stateParameter: d15a80f327

00:41:29,784 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-16) code: AQAqTo8KBjmV_PNVcdq9QjIGi2N27XICop3OhI8NPSltKb1ZTaNojJRMEE70EeNHlzichvLGBU4M-

95q8cIBNxaB3j_nl38s7O8SHUZrEzTVJQFhdRCRefoVJMAiifZqZYAd5t7cyQlRYlXmwBQmZQBLXhCf6O3I7biGDcBsizqd-z9dSxvCc-F2f4Q1Xxvi-cRPLtxqGj0bzY3QL4mUGqhksSELGrMqKPHz8n89o2BxKhAz-muPgYNcS1-

PeRD4h6tSWIIt1dEhLJ_7HwGCme7x9YB9l86IMYfFcCUAB_QNoPZusKnKoNMgXF1KUtFgbcv_63uCz_9b_M___euUmylX

00:41:29,785 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-16) credentials: #OAuth20Credentials# | code=': AQAqTo8KBjmV_PNVcdq9QjIGi2N27XICop3OhI8NPSltKb1ZTaNojJRMEE70EeNHlzichvLGBU4M-

95q8cIBNxaB3j_nl38s7O8SHUZrEzTVJQFhdRCRefoVJMAiifZqZYAd5t7cyQlRYlXmwBQmZQBLXhCf6O3I7biGDcBsizqd-z9dSxvCc-F2f4Q1Xxvi-cRPLtxqGj0bzY3QL4mUGqhksSELGrMqKPHz8n89o2BxKhAz-muPgYNcS1-

PeRD4h6tSWIIt1dEhLJ_7HwGCme7x9YB9l86IMYfFcCUAB_QNoPZusKnKoNMgXF1KUtFgbcv_63uCz_9b_M___euUmylX | clientName: FacebookClient |

00:41:29,785 DEBUG [org.pac4j.oauth.client.FacebookClient] (default task-16) credentials : #OAuth20Credentials# | code=': AQAqTo8KBjmV_PNVcdq9QjIGi2N27XICop3OhI8NPSltKb1ZTaNojJRMEE70EeNHlzichvLGBU4M-

95q8cIBNxaB3j_nl38s7O8SHUZrEzTVJQFhdRCRefoVJMAiifZqZYAd5t7cyQlRYlXmwBQmZQBLXhCf6O3I7biGDcBsizqd-z9dSxvCc-F2f4Q1Xxvi-cRPLtxqGj0bzY3QL4mUGqhksSELGrMqKPHz8n89o2BxKhAz-muPgYNcS1-

PeRD4h6tSWIIt1dEhLJ_7HwGCme7x9YB9l86IMYfFcCUAB_QNoPZusKnKoNMgXF1KUtFgbcv_63uCz_9b_M___euUmylX | clientName: FacebookClient |

00:41:29,785 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-16) code: AQAqTo8KBjmV_PNVcdq9QjIGi2N27XICop3OhI8NPSltKb1ZTaNojJRMEE70EeNHlzichvLGBU4M-

95q8cIBNxaB3j_nl38s7O8SHUZrEzTVJQFhdRCRefoVJMAiifZqZYAd5t7cyQlRYlXmwBQmZQBLXhCf6O3I7biGDcBsizqd-z9dSxvCc-F2f4Q1Xxvi-cRPLtxqGj0bzY3QL4mUGqhksSELGrMqKPHz8n89o2BxKhAz-muPgYNcS1-

PeRD4h6tSWIIt1dEhLJ_7HwGCme7x9YB9l86IMYfFcCUAB_QNoPZusKnKoNMgXF1KUtFgbcv_63uCz_9b_M___euUmylX

00:41:30,014 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-16) accessToken: OAuth2AccessToken

{access_token=EAAFAwjKyEXYBANlE59EvzuoPSLzuMjnMdofoLJpAWW2xEZAkNIF0XgBnUJkrvshshdFUGIfyxwSc08hBvIXOSKXQvP7XIhiKUkkb2QizRTkErxHSTCzfWNgYL0ZCzp24faXEGahlgEzq6Ntx8aY3GwbfyLmzIZD, token_type=bearer, expires_in=5156628, refresh_token=null,

scope=null}

00:41:30,014 DEBUG [org.pac4j.oauth.client.BaseOAuthClient] (default task-16) accessToken: OAuth2AccessToken

{access_token=EAAFAwjKyEXYBANlE59EvzuoPSLzuMjnMdofoLJpAWW2xEZAkNIF0XgBnUJkrvshshdFUGIfyxwSc08hBvIXOSKXQvP7XIhiKUkkb2QizRTkErxHSTCzfWNgYL0ZCzp24faXEGahlgEzq6Ntx8aY3GwbfyLmzIZD, token_type=bearer, expires_in=5156628, refresh_token=null,

scope=null} / dataUrl: https://graph.facebook.com/v2.4/me?

fields=id,name,first_name,middle_name,last_name,gender,locale,languages,link,third_party_id,timezone,updated_time,verified,bio,birthday,education,email,hometown,interested_in,location,political,favorite_athletes,favorite_teams,quotes,re

lationship_status,religion,significant_other,website,work

00:41:30,162 DEBUG [org.pac4j.oauth.client.BaseOAuthClient] (default task-16) Request took: 148 ms for: https://graph.facebook.com/v2.4/me?

fields=id,name,first_name,middle_name,last_name,gender,locale,languages,link,third_party_id,timezone,updated_time,verified,bio,birthday,education,email,hometown,interested_in,location,political,favorite_athletes,favorite_teams,quotes,re

lationship_status,religion,significant_other,website,work

00:41:30,163 DEBUG [org.pac4j.oauth.client.BaseOAuthClient] (default task-16) response code: 200 / response body: {"id":"305660026447164","name":"Bal\u00e1zs Bakai","first_name":"Bal

\u00e1zs","last_name":"Bakai","gender":"male","locale":"hu_HU","link":"https:\/\/www.facebook.com\/app_scoped_user_id\/305660026447164\/","third_party_id":"HwgMyUOmpoACdfEPMqXzd6dLU6Y","timezone":2,"updated_time":"2016-09-

28T13:18:15+0000","verified":true,"birthday":"10\/20\/1984","email":"bakaibalazs\u0040gmail.com"}

00:41:30,785 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) identifier: 305660026447164

00:41:30,785 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: name / value: Balázs Bakai / class java.lang.String

00:41:30,785 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: first_name / value: Balázs / class java.lang.String

00:41:30,785 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: last_name / value: Bakai / class java.lang.String

00:41:30,786 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: link / value: https://www.facebook.com/app_scoped_user_id/305660026447164/ / class java.lang.String

00:41:30,786 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: third_party_id / value: HwgMyUOmpoACdfEPMqXzd6dLU6Y / class java.lang.String

00:41:30,786 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: email / value: bakai...@gmail.com / class java.lang.String

00:41:30,786 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: timezone / value: 2 / class java.lang.Integer

00:41:30,786 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: verified / value: true / class java.lang.Boolean

00:41:30,788 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: gender / value: MALE / class org.pac4j.core.profile.Gender

00:41:30,788 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: locale / value: hu_HU / class java.util.Locale

00:41:30,788 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: updated_time / value: 2016-09-28T15:18:15CEST / class org.pac4j.core.profile.FormattedDate

00:41:30,789 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: birthday / value: 10/20/1984 / class org.pac4j.core.profile.FormattedDate

00:41:30,789 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-16) add access_token:

EAAFAwjKyEXYBANlE59EvzuoPSLzuMjnMdofoLJpAWW2xEZAkNIF0XgBnUJkrvshshdFUGIfyxwSc08hBvIXOSKXQvP7XIhiKUkkb2QizRTkErxHSTCzfWNgYL0ZCzp24faXEGahlgEzq6Ntx8aY3GwbfyLmzIZD to profile

00:41:30,789 DEBUG [org.pac4j.oauth.profile.facebook.FacebookProfile] (default task-16) converted to => key: access_token / value:

EAAFAwjKyEXYBANlE59EvzuoPSLzuMjnMdofoLJpAWW2xEZAkNIF0XgBnUJkrvshshdFUGIfyxwSc08hBvIXOSKXQvP7XIhiKUkkb2QizRTkErxHSTCzfWNgYL0ZCzp24faXEGahlgEzq6Ntx8aY3GwbfyLmzIZD / class java.lang.String

00:41:30,790 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-16) profile: #FacebookProfile# | id: 305660026447164 | attributes: {birthday=10/20/1984, updated_time=2016-09-28T15:18:15CEST, gender=MALE,

timezone=2, link=https://www.facebook.com/app_scoped_user_id/305660026447164/, verified=true, last_name=Bakai, third_party_id=HwgMyUOmpoACdfEPMqXzd6dLU6Y, locale=hu_HU,

access_token=EAAFAwjKyEXYBANlE59EvzuoPSLzuMjnMdofoLJpAWW2xEZAkNIF0XgBnUJkrvshshdFUGIfyxwSc08hBvIXOSKXQvP7XIhiKUkkb2QizRTkErxHSTCzfWNgYL0ZCzp24faXEGahlgEzq6Ntx8aY3GwbfyLmzIZD, name=Balázs Bakai, first_name=Balázs,

email=bakai...@gmail.com} | roles: [] | permissions: [] | isRemembered: false |

00:41:30,790 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-16) Discard old session and replace by a new one...

00:41:30,799 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-16) redirectUrl: http://localhost:8080/MY/facebook-servlet/login

00:41:30,810 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-17) === SECURITY ===

00:41:30,811 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-17) url: http://localhost:8080/MY/facebook-servlet/login

00:41:30,811 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-17) matchers: null

00:41:30,811 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-17) clients: FacebookClient

00:41:30,811 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-17) currentClients: [#FacebookClient# | name: FacebookClient | callbackUrl: http://localhost:8080/MY/callback?client_name=FacebookClient |

callbackUrlResolver: org.pac4j.core.http.DefaultCallbackUrlResolver@c39564c | ajaxRequestResolver: org.pac4j.core.http.DefaultAjaxRequestResolver@67a3517d |]

00:41:30,811 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-17) loadProfilesFromSession: true

00:41:30,812 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-17) profiles: [#FacebookProfile# | id: 305660026447164 | attributes: {birthday=10/20/1984, updated_time=2016-09-28T15:18:15CEST, gender=MALE, timezone=2,

link=https://www.facebook.com/app_scoped_user_id/305660026447164/, verified=true, last_name=Bakai, third_party_id=HwgMyUOmpoACdfEPMqXzd6dLU6Y, locale=hu_HU,

access_token=EAAFAwjKyEXYBANlE59EvzuoPSLzuMjnMdofoLJpAWW2xEZAkNIF0XgBnUJkrvshshdFUGIfyxwSc08hBvIXOSKXQvP7XIhiKUkkb2QizRTkErxHSTCzfWNgYL0ZCzp24faXEGahlgEzq6Ntx8aY3GwbfyLmzIZD, name=Balázs Bakai, first_name=Balázs,

email=bakai...@gmail.com} | roles: [] | permissions: [] | isRemembered: false |]

00:41:30,812 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-17) authorizers: securityHeaders

00:41:30,812 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-17) Checking authorizer: org.pac4j.core.authorization.authorizer.CacheControlHeader@7fae4077 -> true

00:41:30,812 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-17) Checking authorizer: org.pac4j.core.authorization.authorizer.XContentTypeOptionsHeader@6afe98b6 -> true

00:41:30,814 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-17) Checking authorizer: org.pac4j.core.authorization.authorizer.StrictTransportSecurityHeader@124af56 -> true

00:41:30,814 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-17) Checking authorizer: org.pac4j.core.authorization.authorizer.XFrameOptionsHeader@145e56fb -> true

00:41:30,814 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-17) Checking authorizer: org.pac4j.core.authorization.authorizer.XSSProtectionHeader@9a5d273 -> true

00:41:30,814 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-17) authenticated and authorized -> grant access

00:41:30,818 WARN [org.jboss.weld.Interceptor] (default task-17) WELD-001703: Unable to determine the @Intercepted Bean<?> for [UnbackedAnnotatedField] @Inject @Intercepted private

com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequired.interceptedBean

00:41:30,822 INFO [stdout] (Log4j2-AsyncLogger[AsyncContext@1106fe3b]1) 00:41:30.821 [default task-17] TRACE hu.et.util.logging.LoggingInterceptor -

HU.ET.SERVLET.FACEBOOKSERVLET.INIT:io.undertow.servlet.spec.ServletConfigImpl@2bdc6810,

00:41:30,832 INFO [stdout] (Log4j2-AsyncLogger[AsyncContext@1106fe3b]1) 00:41:30.831 [default task-17] TRACE hu.et.util.logging.LoggingInterceptor - HU.ET.SERVLET.FACEBOOKSERVLET.SERVICE:HttpServletRequestImpl [ GET /MY/facebook-

servlet/login ], io.undertow.servlet.spec.HttpServletResponseImpl@70df1b6e,

00:41:30,838 INFO [org.pac4j.core.config.ConfigBuilder] (default task-18) Build the configuration from factory: hu.et.util.security.Pac4JConfigFactory

00:41:30,840 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: clients: FormClient

00:41:30,840 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: authorizers: securityHeaders

00:41:30,840 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: matchers: null

00:41:30,840 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) Boolean param: multiProfile: null

00:41:30,841 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: clientsFactory: null

00:41:30,841 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: isAjax: null

00:41:30,841 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: stateless: null

00:41:30,841 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: requireAnyRole: null

00:41:30,841 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: requireAllRoles: null

00:41:30,841 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: clientName: null

00:41:30,841 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: authorizerName: null

00:41:30,841 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-18) String param: matcherName: null

00:41:30,845 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-18) === SECURITY ===

00:41:30,845 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-18) url: http://localhost:8080/MY/pages/home.jsf

00:41:30,845 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-18) matchers: null

00:41:30,845 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-18) clients: FormClient

00:41:30,846 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-18) currentClients: [#FormClient# | callbackUrl: http://localhost:8080/MY/callback?client_name=FormClient | name: FormClient | loginUrl:

profileCreator: org.pac4j.core.profile.creator.AuthenticatorProfileCreator@2af5a9ec |]

00:41:30,846 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-18) loadProfilesFromSession: true

00:41:30,846 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-18) profiles: [#FacebookProfile# | id: 305660026447164 | attributes: {birthday=10/20/1984, updated_time=2016-09-28T15:18:15CEST, gender=MALE, timezone=2,

link=https://www.facebook.com/app_scoped_user_id/305660026447164/, verified=true, last_name=Bakai, third_party_id=HwgMyUOmpoACdfEPMqXzd6dLU6Y, locale=hu_HU,

access_token=EAAFAwjKyEXYBANlE59EvzuoPSLzuMjnMdofoLJpAWW2xEZAkNIF0XgBnUJkrvshshdFUGIfyxwSc08hBvIXOSKXQvP7XIhiKUkkb2QizRTkErxHSTCzfWNgYL0ZCzp24faXEGahlgEzq6Ntx8aY3GwbfyLmzIZD, name=Balázs Bakai, first_name=Balázs,

email=bakai...@gmail.com} | roles: [] | permissions: [] | isRemembered: false |]

00:41:30,846 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-18) authorizers: securityHeaders

00:41:30,847 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-18) Checking authorizer: org.pac4j.core.authorization.authorizer.CacheControlHeader@7fae4077 -> true

00:41:30,847 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-18) Checking authorizer: org.pac4j.core.authorization.authorizer.XContentTypeOptionsHeader@6afe98b6 -> true

00:41:30,847 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-18) Checking authorizer: org.pac4j.core.authorization.authorizer.StrictTransportSecurityHeader@124af56 -> true

00:41:30,847 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-18) Checking authorizer: org.pac4j.core.authorization.authorizer.XFrameOptionsHeader@145e56fb -> true

00:41:30,847 DEBUG [org.pac4j.core.authorization.checker.DefaultAuthorizationChecker] (default task-18) Checking authorizer: org.pac4j.core.authorization.authorizer.XSSProtectionHeader@9a5d273 -> true

00:41:30,848 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-18) authenticated and authorized -> grant access

00:41:30,875 INFO [stdout] (Log4j2-AsyncLogger[AsyncContext@1106fe3b]1) 00:41:30.875 [default task-18] TRACE hu.et.util.logging.LoggingInterceptor - HU.ET.UTIL.SECURITY.PAC4JUTIL.ISAUTHENTICATED:

00:41:30,881 INFO [stdout] (Log4j2-AsyncLogger[AsyncContext@1106fe3b]1) 00:41:30.881 [default task-18] TRACE hu.et.util.logging.LoggingInterceptor - HU.ET.UTIL.SECURITY.PAC4JUTIL.GETPAC4JINFO:

To unsubscribe from this group and stop receiving emails from it, send an email to pac4j-users...@googlegroups.com.

Jérôme LELEU

unread,

Oct 1, 2016, 6:23:11 AM10/1/16

to Balázs Bakai, pac4j-users

Hi,

Here is an interesting debug log: sessionState: 1594598229 / stateParameter: 3420d4aac5

You have a different state in session than the one returned by Facebook. Very strange!

I just added a log to see the state saved in session: https://github.com/pac4j/pac4j/commit/dfcc8bd13590cb9067454624235bc8de1f49e19d

Can you test again with 1.9.3-SNAPSHOT and post the logs?

Thanks.

Best regards,

Jérôme

To unsubscribe from this group and stop receiving emails from it, send an email to pac4j-users+unsubscribe@googlegroups.com.

Balázs Bakai

unread,

Oct 1, 2016, 11:31:32 AM10/1/16

to pac4j-users, bakai...@gmail.com

Hi!

At first thank you for your help! :)

I notices these lines:

17:28:53,252 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) requestedUrl: http://localhost:8080/MY/facebook-servlet/login

17:28:53,256 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-28) save sessionState: 3ec83a558a

17:28:53,262 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-28) save sessionState: 36343a11e5

This is the debug log:

17:28:48,170 INFO [stdout] (default task-22) SESSION CREATED------------------WoC8qZeEnBsVWTAUuNgq412nIlwXgx7Pn_-KrU7l

17:28:53,203 INFO [org.pac4j.core.config.ConfigBuilder] (default task-28) Build the configuration from factory: hu.et.util.security.Pac4JConfigFactory

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: clients: FacebookClient

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: authorizers: securityHeaders

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: matchers: null

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) Boolean param: multiProfile: null

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: clientsFactory: null

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: isAjax: null

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: stateless: null

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: requireAnyRole: null

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: requireAllRoles: null

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: clientName: null

17:28:53,244 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: authorizerName: null

17:28:53,245 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-28) String param: matcherName: null

17:28:53,251 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) === SECURITY ===

17:28:53,251 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) url: http://localhost:8080/MY/facebook-servlet/login

17:28:53,251 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) matchers: null

17:28:53,251 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) clients: FacebookClient

17:28:53,251 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) currentClients: [#FacebookClient# | name: FacebookClient | callbackUrl: http://localhost:8080/MY/callback?client_name=FacebookClient |

callbackUrlResolver: org.pac4j.core.http.DefaultCallbackUrlResolver@59b6d16d | ajaxRequestResolver: org.pac4j.core.http.DefaultAjaxRequestResolver@211a5cf9 |]

17:28:53,251 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) loadProfilesFromSession: true

17:28:53,252 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) profiles: []

17:28:53,252 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) Starting authentication

17:28:53,252 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-28) requestedUrl: http://localhost:8080/MY/facebook-servlet/login

17:28:53,256 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-28) save sessionState: 3ec83a558a

17:28:53,262 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-28) save sessionState: 36343a11e5

17:28:53,265 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-28) authorizationUrl: https://www.facebook.com/v2.5/dialog/oauth?client_id=352677795074422&redirect_uri=http%3A%2F%2Flocalhost%3A8080%2FMY%2Fcallback

%3Fclient_name%3DFacebookClient&scope=user_birthday%2Cemail&state=36343a11e5

17:28:53,405 INFO [org.pac4j.core.config.ConfigBuilder] (default task-29) Build the configuration from factory: hu.et.util.security.Pac4JConfigFactory

17:28:53,406 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-29) String param: defaultUrl: pages/home.jsf

17:28:53,407 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-29) Boolean param: multiProfile: true

17:28:53,407 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-29) Boolean param: renewSession: true

17:28:53,407 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-29) String param: clientsFactory: null

17:28:53,407 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-29) === CALLBACK ===

17:28:53,408 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-29) client: #FacebookClient# | name: FacebookClient | callbackUrl: http://localhost:8080/MY/callback?client_name=FacebookClient | callbackUrlResolver:

org.pac4j.core.http.DefaultCallbackUrlResolver@332daf5 | ajaxRequestResolver: org.pac4j.core.http.DefaultAjaxRequestResolver@5f4133e2 |

17:28:53,408 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-29) save sessionState: 069051d460

17:28:53,409 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-29) sessionState: 069051d460 / stateParameter: 36343a11e5

17:28:53,410 ERROR [io.undertow.request] (default task-29) UT005023: Exception handling request to /MY/callback: org.pac4j.oauth.exception.OAuthCredentialsException: State parameter mismatch: session expired or possible threat of

cross-site request forgery

at org.pac4j.oauth.client.BaseOAuth20StateClient.getOAuthCredentials(BaseOAuth20StateClient.java:70)

Jérôme LELEU

unread,

Oct 3, 2016, 4:24:50 AM10/3/16

to Balázs Bakai, pac4j-users

Hi,

So the state is generated and saved twice, the second one is transmitted to Facebook. What I don't understand is why a new one seems to be generated before the comparison:

17:28:53,408 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-29) save sessionState: 069051d460

17:28:53,409 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-29) sessionState: 069051d460 / stateParameter: 36343a11e5

Can you put a breakpoint on the "save sessionState" log to see the stack trace and the caller?

Thanks.

Best regards,

Jérôme

Balázs Bakai

unread,

Oct 3, 2016, 6:51:47 AM10/3/16

to pac4j-users, bakai...@gmail.com

Hi!

I made the debugging.

This is the server output log:

12:45:58,216 INFO [org.pac4j.core.config.ConfigBuilder] (default task-7) Build the configuration from factory: hu.et.util.security.Pac4JConfigFactory

12:45:58,235 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: clients: FacebookClient

12:45:58,235 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: authorizers: securityHeaders

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: matchers: null

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) Boolean param: multiProfile: null

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: clientsFactory: null

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: isAjax: null

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: stateless: null

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: requireAnyRole: null

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: requireAllRoles: null

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: clientName: null

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: authorizerName: null

12:45:58,236 DEBUG [org.pac4j.j2e.filter.SecurityFilter] (default task-7) String param: matcherName: null

12:45:58,238 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) === SECURITY ===

12:45:58,238 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) url: http://localhost:8080/ElsoTalalkozas/facebook-servlet/login

12:45:58,238 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) matchers: null

12:45:58,238 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) clients: FacebookClient

12:45:58,239 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) currentClients: [#FacebookClient# | name: FacebookClient | callbackUrl: http://localhost:8080/ElsoTalalkozas/callback?client_name=FacebookClient | callbackUrlResolver: org.pac4j.core.http.DefaultCallbackUrlResolver@5916979a | ajaxRequestResolver: org.pac4j.core.http.DefaultAjaxRequestResolver@31689672 |]

12:45:58,239 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) loadProfilesFromSession: true

12:45:58,239 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) profiles: []

12:45:58,239 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) Starting authentication

12:45:58,239 DEBUG [org.pac4j.core.engine.DefaultSecurityLogic] (default task-7) requestedUrl: http://localhost:8080/ElsoTalalkozas/facebook-servlet/login

12:46:15,210 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-7) save sessionState: 445ff7cb82

12:46:20,174 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-7) save sessionState: cba1d816b0

12:46:22,501 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-7) authorizationUrl: https://www.facebook.com/v2.5/dialog/oauth?client_id=352677795074422&redirect_uri=http%3A%2F%2Flocalhost%3A8080%2FElsoTalalkozas%2Fcallback%3Fclient_name%3DFacebookClient&scope=user_birthday%2Cemail&state=cba1d816b0

12:46:46,750 INFO [org.pac4j.core.config.ConfigBuilder] (default task-8) Build the configuration from factory: hu.et.util.security.Pac4JConfigFactory

12:46:46,787 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-8) String param: defaultUrl: pages/home.jsf

12:46:46,788 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-8) Boolean param: multiProfile: true

12:46:46,789 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-8) Boolean param: renewSession: true

12:46:46,789 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-8) String param: clientsFactory: null

12:46:46,790 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-8) === CALLBACK ===

12:46:46,792 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-8) client: #FacebookClient# | name: FacebookClient | callbackUrl: http://localhost:8080/ElsoTalalkozas/callback?client_name=FacebookClient | callbackUrlResolver: org.pac4j.core.http.DefaultCallbackUrlResolver@4551a2ff | ajaxRequestResolver: org.pac4j.core.http.DefaultAjaxRequestResolver@50d533ab |

12:46:57,997 DEBUG [org.pac4j.oauth.client.BaseOAuth20Client] (default task-8) save sessionState: 9f6c064019

...

And I attached the debug stack (debug stack.png) when after this log record shown: save sessionState: 9f6c064019

debug stack.png

Jérôme LELEU

unread,

Oct 4, 2016, 3:43:59 AM10/4/16

to Balázs Bakai, pac4j-users

Hi,

I don't understand this stack trace at the second "save sessionState": the FacebookClient should have already been initialized at the first call.

Are you sure of this screenshot?

Can you put a breakpoint in the internalInit method of the FacebookClient to see how many times it's called? It should be only once.

Thanks.

Best regards,

Jérôme

Balázs Bakai

unread,

Oct 4, 2016, 3:53:28 AM10/4/16

to pac4j-users, bakai...@gmail.com

Ok, soon I will try you suggested, but I attached my config files, maybe I made a mistake somewhere.

This is the relevant part of my web.xml configuration:

<filter-name>FormFilter</filter-name>

<filter-class>org.pac4j.j2e.filter.SecurityFilter</filter-class>

<init-param>

<param-name>configFactory</param-name>

<param-value>hu.et.util.security.Pac4JConfigFactory</param-value>

</init-param>

<init-param>

<param-name>clients</param-name>

<param-value>FormClient</param-value>

</init-param>

<init-param>

<param-name>authorizers</param-name>

<param-value>securityHeaders</param-value>

</init-param>

</filter>

<filter-mapping>

<filter-name>FormFilter</filter-name>

<url-pattern>/pages/*</url-pattern>

<dispatcher>REQUEST</dispatcher>

</filter-mapping>

<filter-name>FacebookFilter</filter-name>

<filter-class>org.pac4j.j2e.filter.SecurityFilter</filter-class>

<init-param>

<param-name>configFactory</param-name>

<param-value>hu.et.util.security.Pac4JConfigFactory</param-value>

</init-param>

<init-param>

<param-name>clients</param-name>

<param-value>FacebookClient</param-value>

</init-param>

<init-param>

<param-name>authorizers</param-name>

<param-value>securityHeaders</param-value>

</init-param>

</filter>

<filter-mapping>

<filter-name>FacebookFilter</filter-name>

<url-pattern>/facebook-servlet/*</url-pattern>

<dispatcher>REQUEST</dispatcher>

</filter-mapping>

<filter-name>callbackFilter</filter-name>

<filter-class>org.pac4j.j2e.filter.CallbackFilter</filter-class>

<init-param>

<param-name>configFactory</param-name>

<param-value>hu.et.util.security.Pac4JConfigFactory</param-value>

</init-param>

<init-param>

<param-name>defaultUrl</param-name>

<param-value>pages/home.jsf</param-value>

</init-param>

<init-param>

<param-name>renewSession</param-name>

<param-value>true</param-value>

</init-param>

<init-param>

<param-name>multiProfile</param-name>

<param-value>true</param-value>

</init-param>

</filter>

<filter-mapping>

<filter-name>callbackFilter</filter-name>

<url-pattern>/callback</url-pattern>

<dispatcher>REQUEST</dispatcher>

</filter-mapping>

<filter-name>logoutFilter</filter-name>

<filter-class>org.pac4j.j2e.filter.ApplicationLogoutFilter</filter-class>

<init-param>

<param-name>defaultUrl</param-name>

<param-value>index.jsf</param-value>

</init-param>

</filter>

<filter-mapping>

<filter-name>logoutFilter</filter-name>

<url-pattern>/logout</url-pattern>

<dispatcher>REQUEST</dispatcher>

</filter-mapping>

And this is my config factory (hu.et.util.security.Pac4JConfigFactory)

public class Pac4JConfigFactory implements ConfigFactory {

@Override

public Config build() {

FormClient formClient = new FormClient(AppResource.getSystemProperty("basepath") + "/login.jsf", new Pac4JUsernamePasswordAuthenticator());

FacebookClient facebookClient = new FacebookClient(AppResource.getSystemProperty("facebook.key"),AppResource.getSystemProperty("facebook.secret"));

facebookClient.setScope("user_birthday,email");

Clients clients = new Clients(AppResource.getSystemProperty("basepath") + "/callback", formClient, facebookClient);

Config config = new Config(clients);

return config;

}

To unsubscribe from this group and stop receiving emails from it, send an email to pac4j-users...@googlegroups.com.

Balázs Bakai

unread,

Oct 4, 2016, 4:13:07 AM10/4/16

to pac4j-users, bakai...@gmail.com

ohh, I 've just found the problem:

I removed these lines from the CallbackFilter in web.xml. Now, it works!

<init-param>

<param-name>configFactory</param-name>

<param-value>hu.et.util.security.Pac4JConfigFactory</param-value>

</init-param>

This is the corrected web.xml:

Balázs Bakai

unread,

Oct 4, 2016, 4:18:47 AM10/4/16

to pac4j-users, bakai...@gmail.com

hmm, but It is interesting. Now FaceBook login works, but at FormAuthentication I got this exception:

10:17:05,997 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-64) String param: defaultUrl: pages/home.jsf

10:17:05,997 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-64) Boolean param: multiProfile: true

10:17:05,997 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-64) Boolean param: renewSession: true

10:17:05,997 DEBUG [org.pac4j.j2e.filter.CallbackFilter] (default task-64) String param: clientsFactory: null

10:17:05,999 DEBUG [org.pac4j.core.engine.J2ERenewSessionCallbackLogic] (default task-64) === CALLBACK ===

10:17:05,999 ERROR [io.undertow.request] (default task-64) UT005023: Exception handling request to /ElsoTalalkozas/callback: org.pac4j.core.exception.TechnicalException: clients cannot be null

at org.pac4j.core.util.CommonHelper.assertTrue(CommonHelper.java:132)

at org.pac4j.core.util.CommonHelper.assertNotNull(CommonHelper.java:153)

at org.pac4j.core.engine.DefaultCallbackLogic.perform(DefaultCallbackLogic.java:67)