[
https://issues.jboss.org/browse/WFLY-8431?page=com.atlassian.jira.plugin....
]
István Tóth edited comment on WFLY-8431 at 3/23/17 10:39 AM:
-------------------------------------------------------------
Further analysis:
In the above example the following code snippet registers the AuthConfiProvider:
{{logger.info("about to register JASPI SAM.");
AuthConfigFactory acf = AuthConfigFactory.getFactory();
logger.info("AuthConfigFactory acf:" + acf);
String providerId = acf.registerConfigProvider(new NFAuthConfigProvider(),
"HttpServlet", getAppContextID(context), "Netfone CRM authentication config
provider");
logger.info("registered JASPI SAM: \"" + providerId +"\"");
return providerId;}}
It is used and called from a @Weblistener contextInitialized() on six deployments.
The relevant log looks like this:
{{2017-03-23 15:16:53,467 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 69) about to register JASPI SAM.
2017-03-23 15:16:53,467 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 72) about to register JASPI SAM.
2017-03-23 15:16:53,468 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) about to register JASPI SAM.
2017-03-23 15:16:53,468 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 70) about to register JASPI SAM.
2017-03-23 15:16:53,469 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 75) about to register JASPI SAM.
2017-03-23 15:16:53,469 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 61) about to register JASPI SAM.
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
7178b09
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 75) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
70750ec0
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 61) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
7178b09
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 69) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
7bb46782
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 70) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
73a9841c
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) registered JASPI SAM: "HttpServletnfcrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 70) registered JASPI SAM: "HttpServletmhcrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 61) registered JASPI SAM:
"HttpServletnfugyfelkaputeszt.sekhmet.netfone.hu "
2017-03-23 15:16:53,471 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 75) registered JASPI SAM: "HttpServletnftccrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:16:53,471 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 72) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
65438534
2017-03-23 15:16:53,471 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 69) registered JASPI SAM:
"HttpServletmhugyfelkaputeszt.sekhmet.netfone.hu "
2017-03-23 15:16:53,471 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 72) registered JASPI SAM:
"HttpServletnftcugyfelkaputeszt.sekhmet.netfone.hu "}}
The takeaway is this:
The contextInitialized() calls are called at the same time by WF.
The AuthConfigFactory.getFactory() method returns different instances for the different
threads because of the first race condition.
The log output from wildfly startup, when the above code snippet is enclosed in a
synchronized(AuthConfigFactory.class) block {} :
{{2017-03-23 15:15:22,044 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 104) about to register JASPI SAM.
2017-03-23 15:15:22,047 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 104) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,047 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 104) registered JASPI SAM: "HttpServletnftccrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:15:22,047 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 77) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,051 INFO [javax.enterprise.resource.webcontainer.jsf.config]
(ServerService Thread Pool -- 104) Initializing Mojarra 2.2.13.SP1 20160303-1204 for
context ''
2017-03-23 15:15:22,055 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 58) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,058 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 66) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,061 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) about to register JASPI SAM.
2017-03-23 15:15:22,061 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,062 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 68) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,062 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) registered JASPI SAM: "HttpServletnfcrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 66) about to register JASPI SAM.
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 66) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 66) registered JASPI SAM:
"HttpServletnfugyfelkaputeszt.sekhmet.netfone.hu "
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 77) about to register JASPI SAM.
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 77) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 77) registered JASPI SAM:
"HttpServletmhugyfelkaputeszt.sekhmet.netfone.hu "
2017-03-23 15:15:22,066 INFO [javax.enterprise.resource.webcontainer.jsf.config]
(ServerService Thread Pool -- 66) Initializing Mojarra 2.2.13.SP1 20160303-1204 for
context ''
2017-03-23 15:15:22,066 INFO [javax.enterprise.resource.webcontainer.jsf.config]
(ServerService Thread Pool -- 58) Initializing Mojarra 2.2.13.SP1 20160303-1204 for
context ''
2017-03-23 15:15:22,066 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 103) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,067 INFO [javax.enterprise.resource.webcontainer.jsf.config]
(ServerService Thread Pool -- 77) Initializing Mojarra 2.2.13.SP1 20160303-1204 for
context ''
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 68) about to register JASPI SAM.
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 103) about to register JASPI SAM.
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 103) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 68) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 103) registered JASPI SAM: "HttpServletmhcrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 68) registered JASPI SAM:
"HttpServletnftcugyfelkaputeszt.sekhmet.netfone.hu "}}
This time the same AuthConfigFactory object is returned to all callers, and JASPIC
authentication works.
was (Author: stoty2):
Further analysis:
In the above example the following code snippet registers the AuthConfiProvider:
{{
logger.info("about to register JASPI SAM.");
AuthConfigFactory acf = AuthConfigFactory.getFactory();
logger.info("AuthConfigFactory acf:" + acf);
String providerId = acf.registerConfigProvider(new NFAuthConfigProvider(),
"HttpServlet", getAppContextID(context), "Netfone CRM authentication config
provider");
logger.info("registered JASPI SAM: \"" + providerId +"\"");
return providerId;
}}
It is used and called from a @Weblistener contextInitialized() on six deployments.
The relevant log looks like this:
{{
2017-03-23 15:16:53,467 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 69) about to register JASPI SAM.
2017-03-23 15:16:53,467 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 72) about to register JASPI SAM.
2017-03-23 15:16:53,468 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) about to register JASPI SAM.
2017-03-23 15:16:53,468 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 70) about to register JASPI SAM.
2017-03-23 15:16:53,469 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 75) about to register JASPI SAM.
2017-03-23 15:16:53,469 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 61) about to register JASPI SAM.
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
7178b09
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 75) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
70750ec0
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 61) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
7178b09
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 69) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
7bb46782
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 70) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
73a9841c
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) registered JASPI SAM: "HttpServletnfcrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 70) registered JASPI SAM: "HttpServletmhcrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:16:53,470 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 61) registered JASPI SAM:
"HttpServletnfugyfelkaputeszt.sekhmet.netfone.hu "
2017-03-23 15:16:53,471 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 75) registered JASPI SAM: "HttpServletnftccrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:16:53,471 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 72) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@
65438534
2017-03-23 15:16:53,471 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 69) registered JASPI SAM:
"HttpServletmhugyfelkaputeszt.sekhmet.netfone.hu "
2017-03-23 15:16:53,471 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 72) registered JASPI SAM:
"HttpServletnftcugyfelkaputeszt.sekhmet.netfone.hu "
}}
The takeaway is this:
The contextInitialized() calls are called at the same time by WF.
The AuthConfigFactory.getFactory() method returns different instances for the different
threads because of the first race condition.
The log output from wildfly startup, when the above code snippet is enclosed in a
synchronized(AuthConfigFactory.class) block {} :
{{
2017-03-23 15:15:22,044 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 104) about to register JASPI SAM.
2017-03-23 15:15:22,047 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 104) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,047 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 104) registered JASPI SAM: "HttpServletnftccrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:15:22,047 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 77) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,051 INFO [javax.enterprise.resource.webcontainer.jsf.config]
(ServerService Thread Pool -- 104) Initializing Mojarra 2.2.13.SP1 20160303-1204 for
context ''
2017-03-23 15:15:22,055 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 58) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,058 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 66) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,061 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) about to register JASPI SAM.
2017-03-23 15:15:22,061 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,062 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 68) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,062 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 58) registered JASPI SAM: "HttpServletnfcrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 66) about to register JASPI SAM.
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 66) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 66) registered JASPI SAM:
"HttpServletnfugyfelkaputeszt.sekhmet.netfone.hu "
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 77) about to register JASPI SAM.
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 77) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,063 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 77) registered JASPI SAM:
"HttpServletmhugyfelkaputeszt.sekhmet.netfone.hu "
2017-03-23 15:15:22,066 INFO [javax.enterprise.resource.webcontainer.jsf.config]
(ServerService Thread Pool -- 66) Initializing Mojarra 2.2.13.SP1 20160303-1204 for
context ''
2017-03-23 15:15:22,066 INFO [javax.enterprise.resource.webcontainer.jsf.config]
(ServerService Thread Pool -- 58) Initializing Mojarra 2.2.13.SP1 20160303-1204 for
context ''
2017-03-23 15:15:22,066 INFO
[se.jiderhamn.classloader.leak.prevention.ClassLoaderLeakPreventor] (ServerService Thread
Pool -- 103) Initializing by loading some known offenders with leak safe classloader
2017-03-23 15:15:22,067 INFO [javax.enterprise.resource.webcontainer.jsf.config]
(ServerService Thread Pool -- 77) Initializing Mojarra 2.2.13.SP1 20160303-1204 for
context ''
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 68) about to register JASPI SAM.
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 103) about to register JASPI SAM.
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 103) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 68) AuthConfigFactory
acf:org.jboss.security.auth.message.config.JBossAuthConfigFactory@7a0df6e8
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 103) registered JASPI SAM: "HttpServletmhcrmteszt.sekhmet.netfone.hu
"
2017-03-23 15:15:22,070 INFO [hu.netfone.security.jaspi.JaspicUtils] (ServerService
Thread Pool -- 68) registered JASPI SAM:
"HttpServletnftcugyfelkaputeszt.sekhmet.netfone.hu "
}}
This time the same AuthConfigFactory object is returned to all callers, and JASPIC
authentication works.
Race conditions in JASPIC registration code
-------------------------------------------
Key: WFLY-8431
URL:
https://issues.jboss.org/browse/WFLY-8431
Project: WildFly
Issue Type: Bug
Components: Security
Affects Versions: 10.1.0.Final
Environment: Centos 7 x86_64, with the included Java 8 environment
Reporter: István Tóth
Assignee: Darran Lofthouse
javax.security.auth.message.config.AuthConfigFactory and
org.jboss.security.auth.message.config.JBossAuthConfigFactory
have race conditions.
1. javax.security.auth.message.config.AuthConfigFactory#getFactory() has a race
condition. The checking and creation of the _factory object is not atomic.
I think the best and simplest solution would be to simply make the getFactory() method
synchronized. (The same method in the Glassfish implmentation is synchronized)
2. The keyTo*Map fields of the
org.jboss.security.auth.message.config.JBossAuthConfigFactory are not thread safe.
Nearly all methods of this class manipulate these, without any synchronization.
In this case I believe that changing those from HashMaps to ConcurrentHashMaps should be
enough to avoid the worst of the races, while incurring a negligible performance penalty.
The methods that modify the maps should also be made synchronized, or rewritten to use
the
atomic ConcurrentHashMaps operations.
A possible workaround is to add a synchronized(AuthConfigFactory.class) block around the
JASPIC initialization code, where the JBossAuthConfigFactory methods are called. Of course
this only works if every webapp on the server can be modified this way.
--
This message was sent by Atlassian JIRA
(v7.2.3#72005)