Web service clients always get "403 Forbidden"

[jewellgm]

Hello,

I am attempting to upgrade an application that's using JBoss AS 7.1.1 to WildFly 8.2.0.  Part of the application exposes stateless session beans to clients as web services.  The application is set up to perform BASIC authentication, and then to authorize particular actions in the web services based on user roles.  The current setup works in 7.1.1, but 8.2.0 is always forbidding the client from proceeding.

I have set TRACE level debugging in both org.jboss.security and org.wildfly.extension.undertow.  The org.jboss.security logging shows that incoming clients are authenticated, and that role mappings are properly loaded.  The undertow logging only shows that a client is authenticated, but nothing is shown regarding authorization.  There are no obvious errors in the server.log.  Based on the observation that no messages regarding authorization appear in the undertow subsystem, I am guessing that this is the source of the problem (but I'm far from positive about this).

Here's the single line in the log file from the undertow subsystem:

2015-04-13 09:56:10,861 TRACE [org.wildfly.extension.undertow] (default task-7) User: org.wildfly.extension.undertow.security.AccountImpl$AccountPrincipal@64 is authenticated

I found a similar problem in this thread:

403 Forbidden using BASIC auth and "other" security domain

I built the wunderboss modules and am trying to deploy it, but have been unsuccessful to this point.  If don't include javax.servlet.api as a dependency in the wunderboss module, deployment fails stating that it can't find javax.servlet.ServletContextListener.  If I do include javax.servlet.api as a dependency, I get a NoClassDefFoundError for org.xml.sax.InputSource.

Can anybody provide any pointers?  Do I really need the wunderboss modules, or is there something else that I'm missing?

Thank you!

[jewellgm]

Wunderboss seems to be a non-starter for me.  During deployment, it's complaining that a required option named "language" is missing.  Searching the source code, "language" should either be "ruby" or "clojure", and I'm using neither.

Does anybody know whether undertow actually supports authorization operations?  Even putting a @PermitAll annotation on the various web service methods doesn't allow those methods to be invoked from an authenticated client.

[jaikiran]

What's wunderboss?

If you application was passing in JBoss AS 7.1 and it's failing in WildFly with this permission issue, you might want to check this specific section named "Access to methods without explicit security metadata, on a secured bean" in the documentation here https://docs.jboss.org/author/display/WFLY8/Securing+EJBs

Of course, I'm assuming that your webservices are backed by EJBs.

If that doesn't help, please post relevant code and the entire exception stacktrace that you are seeing, for a start.

[jewellgm]

Thank you Jaikiran for the response.  To be honest, I don't really know what wunderboss is.  In the thread that I linked to, the person that had the issue said this resolved it.  What I can say, though, is that it's a project hosted on github that seems to be a utility suite.  One of the utilities is a wildfly module, and that module contains a servlet listener.  From the linked thread, it appeared that the servlet listener would resolve the issue of the web service clients always getting a 403 error when authorization was required.

My server.log doesn't contain a single stack trace in it.  As far as I can see, the server thinks everything is just fine.  Only in the client log is there a stack trace, and it shows the 403 error in it.

I'm sorry for the wall of code below, but I think you'd probably want to see all of this.

Here are snippets from various class files and configuration files:

@WebService(endpointInterface = "com.test.TestPort", serviceName = "TestService", portName = "TestServicePort", targetNamespace = "http://www.test.com/wsdl")

@Stateless(name = "PrivateTestBean")

@SecurityDomain("TestAuth")

@TransactionAttribute(TransactionAttributeType.NOT_SUPPORTED)

@SchemaValidation

public class TestBean implements TestBeanLocal, TestBeanRemote {

@RolesAllowed({"INTERNAL_TEST_CLIENT", "AUTHORIZED_USER"})

    @Override

    public void doSomething() {

return;

}

}

Snippets from standalone.xml:

    <management>

        <security-realms>

             <security-realm name="TestRealm">

                <authentication>

                    <jaas name="TestAuth"/>

                </authentication>

            </security-realm>

        </security-realms>

    </management>

           <subsystem xmlns="urn:jboss:domain:security:1.2">

                <security-domain name="TestAuth" cache-type="default">

                    <authentication>

                        <login-module code="org.jboss.security.auth.spi.LdapLoginModule" flag="required">

                            <module-option name="java.naming.factory.initial" value="com.sun.jndi.ldap.LdapCtxFactory"/>

                            <module-option name="java.naming.provider.url" value="ldaps://127.0.0.1:1234"/>

                            <module-option name="java.naming.security.authentication" value="simple"/>

                            <module-option name="principalDNPrefix" value="uid="/>

                            <module-option name="principalDNSuffix" value=",ou=Users,ou=Test,dc=test,dc=com"/>

                            <module-option name="uidAttributeID" value="member"/>

                            <module-option name="matchOnUserDN" value="true"/>

                            <module-option name="rolesCtxDN" value="ou=Groups,ou=Test,dc=test,dc=com"/>

                            <module-option name="roleAttributeID" value="cn"/>

                            <module-option name="roleAttributeIsDN" value="false"/>

                        </login-module>

                        <login-module code="org.jboss.security.auth.spi.RoleMappingLoginModule" flag="required">

                            <module-option name="rolesProperties" value="file:///${jboss.server.config.dir}/test-authorizations.properties"/>

                        </login-module>

                    </authentication>

                </security-domain>

            </security-domains>

        </subsystem>

test-authorizations.properties:

Test_Client_All_Authorizations=AUTHORIZED_USER,VIEW_DATA,UPDATE_DATA

Test_Client_Auth_Grp_1=AUTHORIZED_USER,VIEW_DATA

Test_Client_Auth_Grp_2=AUTHORIZED_USER,UPDATE_DATA

Here's the web.xml:

<web-app xmlns="http://java.sun.com/xml/ns/javaee" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"

    xsi:schemaLocation="http://java.sun.com/xml/ns/javaee http://java.sun.com/xml/ns/javaee/web-app_3_0.xsd"

    version="3.0">

    <security-constraint>

        <web-resource-collection>

            <web-resource-name>HtmlAuth</web-resource-name>

            <description>application security constraints</description>

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

            <http-method>GET</http-method>

            <http-method>POST</http-method>

        </web-resource-collection>

        <auth-constraint>

            <role-name>Test_Client_All_Authorizations</role-name>

            <role-name>Test_Client_Auth_Grp_1</role-name>

            <role-name>Test_Client_Auth_Grp_2</role-name>

        </auth-constraint>

    </security-constraint>

    <login-config>

        <auth-method>BASIC</auth-method>

        <realm-name>TestRealm</realm-name>

    </login-config>

    <security-role>

        <role-name>Test_Client_All_Authorizations</role-name>

    </security-role>

    <security-role>

        <role-name>Test_Client_Auth_Grp_1</role-name>

    </security-role>

    <security-role>

        <role-name>Test_Client_Auth_Grp_2</role-name>

    </security-role>

</web-app>

jboss-web.xml:

<?xml version="1.0" encoding="UTF-8"?>

<jboss-web>

    <security-domain>java:/jaas/TestAuth</security-domain>

</jboss-web>

jboss-webservices.xml:

<?xml version="1.0" encoding="UTF-8"?>

<webservices xmlns="http://www.jboss.com/xml/ns/javaee">

    <context-root>/Test</context-root>

    <port-component>

        <ejb-name>TestBean</ejb-name>

        <port-component-name>TestServicePort</port-component-name>

        <port-component-uri>/services/TestService</port-component-uri>

        <auth-method>BASIC</auth-method>

        <transport-guarantee>NONE</transport-guarantee>

        <secure-wsdl-access>false</secure-wsdl-access>

    </port-component>

</webservices>

When a client attempts to utilize the doSomething() method, here's what I see in the server.log file.  Note that there is no stack trace in this log file!:

2015-04-14 08:58:21,872 TRACE [org.jboss.security] (default task-6) PBOX000200: Begin isValid, principal: org.wildfly.extension.undertow.security.AccountImpl$AccountPrincipal@63, cache entry: null

2015-04-14 08:58:22,356 TRACE [org.jboss.security] (default task-6) PBOX000209: defaultLogin, principal: org.wildfly.extension.undertow.security.AccountImpl$AccountPrincipal@63

2015-04-14 08:58:22,356 TRACE [org.jboss.security] (default task-6) PBOX000221: Begin getAppConfigurationEntry(TestAuth), size: 5

2015-04-14 08:58:22,356 TRACE [org.jboss.security] (default task-6) PBOX000224: End getAppConfigurationEntry(TestAuth), AuthInfo: AppConfigurationEntry[]:

[0]

LoginModule Class: org.jboss.security.auth.spi.RoleMappingLoginModule

ControlFlag: LoginModuleControlFlag: required

Options:

name=uidAttributeID, value=member

name=java.naming.security.authentication, value=simple

name=java.naming.factory.initial, value=com.sun.jndi.ldap.LdapCtxFactory

name=matchOnUserDN, value=true

name=java.naming.provider.url, value=ldaps://127.0.0.1:1234

name=rolesCtxDN, value=ou=Groups,ou=Test,dc=test,dc=com

name=principalDNSuffix, value=,ou=Users,ou=Test,dc=test,dc=com

name=principalDNPrefix, value=uid=

name=roleAttributeIsDN, value=false

name=roleAttributeID, value=cn

[1]

LoginModule Class: org.jboss.security.auth.spi.RoleMappingLoginModule

ControlFlag: LoginModuleControlFlag: required

Options:

name=rolesProperties, value=file:///C:\wildfly-8.2.0.Final\standalone\configuration/test-authorizations.properties

2015-04-14 08:58:22,371 TRACE [org.jboss.security] (default task-6) PBOX000236: Begin initialize method

2015-04-14 08:58:22,371 TRACE [org.jboss.security] (default task-6) PBOX000240: Begin login method

2015-04-14 08:58:22,387 TRACE [org.jboss.security.auth.spi.AbstractServerLoginModule] (default task-6) >>> validatePassword

2015-04-14 08:58:22,387 TRACE [org.jboss.security] (default task-6) PBOX000220: Logging into LDAP server with env {java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, principalDNPrefix=uid=, java.naming.security.principal=uid=c,ou=Users,ou=Test,dc=test,dc=com, roleAttributeID=cn, matchOnUserDN=true, principalDNSuffix=,ou=Users,ou=Test,dc=test,dc=com, rolesCtxDN=ou=Groups,ou=Test,dc=test,dc=com, jboss.security.security_domain=TestAuth, java.naming.provider.url=ldaps://127.0.0.1:1234, roleAttributeIsDN=false, uidAttributeID=member, java.naming.security.authentication=simple, java.naming.security.credentials=******}

2015-04-14 08:58:22,558 TRACE [org.jboss.security] (default task-6) PBOX000271: Logged into LDAP server, context: javax.naming.ldap.InitialLdapContext@35fc34c7

2015-04-14 08:58:22,558 TRACE [org.jboss.security] (default task-6) PBOX000274: Searching rolesCtxDN ou=Groups,ou=TEST,dc=test,dc=com with roleFilter: (member={0}), filterArgs: uid=c,ou=Users,ou=Test,dc=test,dc=com, roleAttr: [cn], searchScope: 2, searchTimeLimit: 10000

2015-04-14 08:58:22,590 TRACE [org.jboss.security] (default task-6) PBOX000275: Checking search result cn=Test_Client_All_Authorizations

2015-04-14 08:58:22,590 TRACE [org.jboss.security] (default task-6) PBOX000268: Assigning user to role Test_Client_All_Authorizations

2015-04-14 08:58:22,590 TRACE [org.jboss.security] (default task-6) PBOX000241: End login method, isValid: true

2015-04-14 08:58:22,590 TRACE [org.jboss.security] (default task-6) PBOX000236: Begin initialize method

2015-04-14 08:58:22,590 TRACE [org.jboss.security] (default task-6) PBOX000240: Begin login method

2015-04-14 08:58:22,590 TRACE [org.jboss.security] (default task-6) PBOX000242: Begin commit method, overall result: true

2015-04-14 08:58:22,590 TRACE [org.jboss.security] (default task-6) PBOX000242: Begin commit method, overall result: true

2015-04-14 08:58:22,605 TRACE [org.jboss.security] (default task-6) PBOX000288: Properties file file:///C:\wildfly-8.2.0.Final\standalone\configuration/test-authorizations.properties loaded, users: [Test_Client_All_Authorizations, Test_Client_Auth_Grp_2, Test_Client_Auth_Grp_1]

2015-04-14 08:58:22,605 TRACE [org.jboss.security] (default task-6) PBOX000210: defaultLogin, login context: javax.security.auth.login.LoginContext@5d621bd6, subject: Subject(1410444927).principals=org.jboss.security.SimplePrincipal@1131868586(c)org.jboss.security.SimpleGroup@2132919860(Roles(members:AUTHORIZED_USER,UPDATE_DATA,Test_Client_Auth_Grp2))org.jboss.security.SimpleGroup@2132919860(CallerPrincipal(members:c))

2015-04-14 08:58:22,605 TRACE [org.jboss.security] (default task-6) PBOX000207: updateCache, input subject: Subject(1410444927).principals=org.jboss.security.SimplePrincipal@1131868586(c)org.jboss.security.SimpleGroup@2132919860(Roles(members:AUTHORIZED_USER,UPDATE_DATA,VIEW_DATA,Test_Client_All_Authorizations))org.jboss.security.SimpleGroup@2132919860(CallerPrincipal(members:c)), cached subject: Subject(1423392503).principals=org.jboss.security.SimplePrincipal@1131868586(c)org.jboss.security.SimpleGroup@2132919860(Roles(members:AUTHORIZED_USER,UPDATE_DATA,VIEW_DATA,Test_Client_All_Authorizations))org.jboss.security.SimpleGroup@2132919860(CallerPrincipal(members:c))

2015-04-14 08:58:22,605 TRACE [org.jboss.security] (default task-6) PBOX000208: Inserted cache info: org.jboss.security.authentication.JBossCachedAuthenticationManager$DomainInfo@7f66f5a4

2015-04-14 08:58:22,605 TRACE [org.jboss.security] (default task-6) PBOX000201: End isValid, result = true

2015-04-14 08:58:22,605 TRACE [org.wildfly.extension.undertow] (default task-6) User: org.wildfly.extension.undertow.security.AccountImpl$AccountPrincipal@63 is authenticated

2015-04-14 08:58:22,636 TRACE [org.jboss.security] (default task-6) PBOX000354: Setting security roles ThreadLocal: null

2015-04-14 08:58:30,000 TRACE [org.jboss.security] (EJB default - 6) PBOX000354: Setting security roles ThreadLocal: {}

2015-04-14 08:58:30,000 TRACE [org.jboss.security] (EJB default - 9) PBOX000354: Setting security roles ThreadLocal: {}

2015-04-14 08:58:30,000 TRACE [org.jboss.security] (EJB default - 9) PBOX000354: Setting security roles ThreadLocal: null

Note that the "Setting security roles ThreadLocal: null (and {})" appear throughout the log, and not just when a client attempts to connect.  I don't know if this is significant.

Finally, here's part of the stack trace that is in the client's log file after the connection attempt is made:

com.sun.xml.internal.ws.client.ClientTransportException: The server sent HTTP status code 403: Forbidden

    at com.sun.xml.internal.ws.transport.http.client.HttpTransportPipe.checkStatusCode(HttpTransportPipe.java:296)

    at com.sun.xml.internal.ws.transport.http.client.HttpTransportPipe.createResponsePacket(HttpTransportPipe.java:245)

    at com.sun.xml.internal.ws.transport.http.client.HttpTransportPipe.process(HttpTransportPipe.java:203)

    at com.sun.xml.internal.ws.transport.http.client.HttpTransportPipe.processRequest(HttpTransportPipe.java:122)

    at com.sun.xml.internal.ws.transport.DeferredTransportPipe.processRequest(DeferredTransportPipe.java:123)

    at com.sun.xml.internal.ws.api.pipe.Fiber.__doRun(Fiber.java:626)

    at com.sun.xml.internal.ws.api.pipe.Fiber._doRun(Fiber.java:585)

    at com.sun.xml.internal.ws.api.pipe.Fiber.doRun(Fiber.java:570)

    at com.sun.xml.internal.ws.api.pipe.Fiber.runSync(Fiber.java:467)

    at com.sun.xml.internal.ws.client.Stub.process(Stub.java:308)

    at com.sun.xml.internal.ws.client.sei.SEIStub.doProcess(SEIStub.java:163)

    at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:98)

    at com.sun.xml.internal.ws.client.sei.SyncMethodHandler.invoke(SyncMethodHandler.java:78)

    at com.sun.xml.internal.ws.client.sei.SEIStub.invoke(SEIStub.java:135)

    at com.sun.proxy.$Proxy74.getDisclaimerData(Unknown Source)

[jaikiran]

Can you attach the entire server.log with that TRACE log enabled? The current log does help a bit, but I haven't been able to get the full picture yet. Furthermore, how is this application packaged? Is it an .ear containing .war and .jar (for EJBs) or is it just a .war containing EJBs?

[jaikiran]

By the way, although the logs suggest this isn't a problem, the right value for the security domain element in your xml is just the security domain name. The usage of JNDI name in that element has been deprecated and doesn't work in some cases. So I would recommend you change it to:

<?xml version="1.0" encoding="UTF-8"?>

<jboss-web>

    <security-domain>TestAuth</security-domain>

</jboss-web>

[jaikiran]

Greg Jewell wrote:

Thank you Jaikiran for the response.  To be honest, I don't really know what wunderboss is.  In the thread that I linked to, the person that had the issue said this resolved it.  What I can say, though, is that it's a project hosted on github that seems to be a utility suite.  One of the utilities is a wildfly module, and that module contains a servlet listener.  From the linked thread, it appeared that the servlet listener would resolve the issue of the web service clients always getting a 403 error when authorization was required.

I just had a look at that linked thread. You can ignore it and the wunderboss reference, since it's unrelated to the issue you are running into.

[jewellgm]

The application is packaged as an ear, with a war file and jar file in the root of the ear.  The war file is pretty sparse, containing only the web.xml and jboss-web.xml files.  The jar file contains all of the EJBs.  The application.xml defines a web module for the war file and an ejb module for the jar.

As you have suggested, I removed the "java:/jaas/" prefix from the security-domain in the jboss-web.xml file.  The behavior remains unchanged.

I will try to get post the server.log, but I need to get approval to do that.  Is there a particular section in the log that you'd like to see?  Perhaps it would be easier if I could target a specific set of messages.

[jaikiran]

Greg Jewell wrote:

I will try to get post the server.log, but I need to get approval to do that.  Is there a particular section in the log that you'd like to see?  Perhaps it would be easier if I could target a specific set of messages.

I'm interested in the TRACE level logs of org.jboss.security, org.jboss.as.ejb3 packages from the point when that action is triggered till the point the browser sees that 403 response.

[jewellgm]

jaikiran pai wrote:

I'm interested in the TRACE level logs of org.jboss.security, org.jboss.as.ejb3 packages from the point when that action is triggered till the point the browser sees that 403 response.

Here's the information you requested.  I'm afraid that it doesn't provide much more information than the log snippet I posted earlier.  I did set the log level for org.jboss.as.ejb3 to TRACE, but lowest level found in the log was DEBUG.  Maybe you're trying to see if something is missing in the log?

2015-04-15 08:07:00,000 DEBUG [org.jboss.as.ejb3] (EJB default - 1) Timer task invoked at: Wed Apr 15 08:07:00 EDT 2015 for timer [id=59ee882a-23de-4007-95af-efe269b46fb7 timedObjectId=Test.timer.ConnectionTimerBean auto-timer?:true persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@3c3244b9 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Wed Apr 15 08:07:00 EDT 2015 timerState=ACTIVE info=null

2015-04-15 08:07:00,000 DEBUG [org.jboss.as.ejb3] (EJB default - 1) Scheduling a single action timer [id=59ee882a-23de-4007-95af-efe269b46fb7 timedObjectId=Test.timer.ConnectionTimerBean auto-timer?:true persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@3c3244b9 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Wed Apr 15 08:07:10 EDT 2015 timerState=IN_TIMEOUT info=null starting at 10000 milliseconds from now

2015-04-15 08:07:00,000 TRACE [org.jboss.security] (EJB default - 1) PBOX000354: Setting security roles ThreadLocal: {}

2015-04-15 08:07:00,000 TRACE [org.jboss.security] (EJB default - 10) PBOX000354: Setting security roles ThreadLocal: {}

2015-04-15 08:07:00,001 TRACE [org.jboss.security] (EJB default - 1) PBOX000354: Setting security roles ThreadLocal: null

2015-04-15 08:07:00,004 TRACE [org.jboss.security] (Thread-17 (HornetQ-client-global-threads-1915138991)) PBOX000354: Setting security roles ThreadLocal: {}

2015-04-15 08:07:00,004 TRACE [org.jboss.security] (Thread-23 (HornetQ-client-global-threads-1915138991)) PBOX000354: Setting security roles ThreadLocal: {}

2015-04-15 08:07:00,004 TRACE [org.jboss.security] (Thread-23 (HornetQ-client-global-threads-1915138991)) PBOX000354: Setting security roles ThreadLocal: {}

2015-04-15 08:07:00,005 TRACE [org.jboss.as.ejb3] (Thread-17 (HornetQ-client-global-threads-1915138991)) 0/20 Free instance: org.jboss.as.ejb3.pool.strictmax.StrictMaxPool@260195b3

2015-04-15 08:07:00,005 TRACE [org.jboss.security] (Thread-17 (HornetQ-client-global-threads-1915138991)) PBOX000354: Setting security roles ThreadLocal: null

2015-04-15 08:07:00,005 TRACE [org.jboss.security] (Thread-23 (HornetQ-client-global-threads-1915138991)) PBOX000354: Setting security roles ThreadLocal: null

2015-04-15 08:07:00,005 TRACE [org.jboss.as.ejb3] (Thread-23 (HornetQ-client-global-threads-1915138991)) 0/20 Free instance: org.jboss.as.ejb3.pool.strictmax.StrictMaxPool@77334f50

2015-04-15 08:07:00,005 TRACE [org.jboss.security] (Thread-23 (HornetQ-client-global-threads-1915138991)) PBOX000354: Setting security roles ThreadLocal: null

2015-04-15 08:07:00,006 TRACE [org.jboss.security] (EJB default - 10) PBOX000354: Setting security roles ThreadLocal: null

2015-04-15 08:07:03,166 TRACE [org.jboss.security] (default task-6) PBOX000200: Begin isValid, principal: org.wildfly.extension.undertow.security.AccountImpl$AccountPrincipal@63, cache entry: null

2015-04-15 08:07:04,025 TRACE [org.jboss.security] (default task-6) PBOX000209: defaultLogin, principal: org.wildfly.extension.undertow.security.AccountImpl$AccountPrincipal@63

2015-04-15 08:07:04,025 TRACE [org.jboss.security] (default task-6) PBOX000221: Begin getAppConfigurationEntry(TestAuth), size: 5

2015-04-15 08:07:04,025 TRACE [org.jboss.security] (default task-6) PBOX000224: End getAppConfigurationEntry(TestAuth), AuthInfo: AppConfigurationEntry[]:

[0]

LoginModule Class: org.jboss.security.auth.spi.LdapLoginModule

ControlFlag: LoginModuleControlFlag: required

Options:

name=uidAttributeID, value=member

name=java.naming.security.authentication, value=simple

name=java.naming.factory.initial, value=com.sun.jndi.ldap.LdapCtxFactory

name=matchOnUserDN, value=true

name=java.naming.provider.url, value=ldaps://127.0.0.1:1234

name=rolesCtxDN, value=ou=Groups,ou=Test,dc=test,dc=com

name=principalDNSuffix, value=,ou=Users,ou=Test,dc=test,dc=com

name=principalDNPrefix, value=uid=

name=roleAttributeIsDN, value=false

name=roleAttributeID, value=cn

[1]

LoginModule Class: org.jboss.security.auth.spi.RoleMappingLoginModule

ControlFlag: LoginModuleControlFlag: required

Options:

name=rolesProperties, value=file:///C:\wildfly-8.2.0.Final\standalone\configuration/test-authorizations.properties

2015-04-15 08:07:04,030 TRACE [org.jboss.security] (default task-6) PBOX000236: Begin initialize method

2015-04-15 08:07:04,030 TRACE [org.jboss.security] (default task-6) PBOX000240: Begin login method

2015-04-15 08:07:04,039 TRACE [org.jboss.security.auth.spi.AbstractServerLoginModule] (default task-6) >>> validatePassword

2015-04-15 08:07:04,040 TRACE [org.jboss.security] (default task-6) PBOX000220: Logging into LDAP server with env {java.naming.factory.initial=com.sun.jndi.ldap.LdapCtxFactory, principalDNPrefix=uid=, java.naming.security.principal=uid=c,ou=Users,ou=Test,dc=test,dc=com, roleAttributeID=cn, matchOnUserDN=true, principalDNSuffix=,ou=Users,ou=Test,dc=test,dc=com, rolesCtxDN=ou=Groups,ou=Test,dc=test,dc=com, jboss.security.security_domain=Test, java.naming.provider.url=ldaps://127.0.0.1:1234, roleAttributeIsDN=false, uidAttributeID=member, java.naming.security.authentication=simple, java.naming.security.credentials=******}

2015-04-15 08:07:04,149 TRACE [org.jboss.security] (default task-6) PBOX000271: Logged into LDAP server, context: javax.naming.ldap.InitialLdapContext@68efb513

2015-04-15 08:07:04,149 TRACE [org.jboss.security] (default task-6) PBOX000274: Searching rolesCtxDN ou=Groups,ou=Test,dc=test,dc=com with roleFilter: (member={0}), filterArgs: uid=c,ou=Users,ou=Test,dc=test,dc=com, roleAttr: [cn], searchScope: 2, searchTimeLimit: 10000

2015-04-15 08:07:04,170 TRACE [org.jboss.security] (default task-6) PBOX000275: Checking search result cn=Test_Client_All_Authorizations

2015-04-15 08:07:04,171 TRACE [org.jboss.security] (default task-6) PBOX000268: Assigning user to role Test_Client_All_Authorizations

2015-04-15 08:07:04,172 TRACE [org.jboss.security] (default task-6) PBOX000241: End login method, isValid: true

2015-04-15 08:07:04,173 TRACE [org.jboss.security] (default task-6) PBOX000236: Begin initialize method

2015-04-15 08:07:04,173 TRACE [org.jboss.security] (default task-6) PBOX000240: Begin login method

2015-04-15 08:07:04,173 TRACE [org.jboss.security] (default task-6) PBOX000242: Begin commit method, overall result: true

2015-04-15 08:07:04,174 TRACE [org.jboss.security] (default task-6) PBOX000242: Begin commit method, overall result: true

2015-04-15 08:07:04,192 TRACE [org.jboss.security] (default task-6) PBOX000288: Properties file file:///C:\wildfly-8.2.0.Final\standalone\configuration/test-authorizations.properties loaded, users: [Test_Client_All_Authorizations, Test_Client_Auth_Grp_2, Test_Client_Auth_Grp_1]

2015-04-15 08:07:04,194 TRACE [org.jboss.security] (default task-6) PBOX000210: defaultLogin, login context: javax.security.auth.login.LoginContext@219490a4, subject: Subject(547622965).principals=org.jboss.security.SimplePrincipal@1166202719(c)org.jboss.security.SimpleGroup@304204962(Roles(members:UPDATE_DATA,VIEW_DATA,Test_Client_All_Authorizations))org.jboss.security.SimpleGroup@304204962(CallerPrincipal(members:c))

2015-04-15 08:07:04,194 TRACE [org.jboss.security] (default task-6) PBOX000207: updateCache, input subject: Subject(547622965).principals=org.jboss.security.SimplePrincipal@1166202719(c)org.jboss.security.SimpleGroup@304204962(Roles(members:UPDATE_DATA,VIEW_DATA,Test_Client_All_Authorizations))org.jboss.security.SimpleGroup@304204962(CallerPrincipal(members:c)), cached subject: Subject(1931745360).principals=org.jboss.security.SimplePrincipal@1166202719(c)org.jboss.security.SimpleGroup@304204962(Roles(members:UPDATE_DATA,VIEW_DATA,Test_Client_All_Authorizations))org.jboss.security.SimpleGroup@304204962(CallerPrincipal(members:c))

2015-04-15 08:07:04,194 TRACE [org.jboss.security] (default task-6) PBOX000208: Inserted cache info: org.jboss.security.authentication.JBossCachedAuthenticationManager$DomainInfo@46b8673e

2015-04-15 08:07:04,195 TRACE [org.jboss.security] (default task-6) PBOX000201: End isValid, result = true

2015-04-15 08:07:04,195 TRACE [org.wildfly.extension.undertow] (default task-6) User: org.wildfly.extension.undertow.security.AccountImpl$AccountPrincipal@63 is authenticated

2015-04-15 08:07:04,212 TRACE [org.jboss.security] (default task-6) PBOX000354: Setting security roles ThreadLocal: null

2015-04-15 08:07:10,001 DEBUG [org.jboss.as.ejb3] (EJB default - 3) Timer task invoked at: Wed Apr 15 08:07:10 EDT 2015 for timer [id=59ee882a-23de-4007-95af-efe269b46fb7 timedObjectId=Test.timer.ConnectionTimerBean auto-timer?:true persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@3c3244b9 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Wed Apr 15 08:07:10 EDT 2015 timerState=ACTIVE info=null

2015-04-15 08:07:10,001 DEBUG [org.jboss.as.ejb3] (EJB default - 3) Scheduling a single action timer [id=59ee882a-23de-4007-95af-efe269b46fb7 timedObjectId=Test.timer.ConnectionTimerBean auto-timer?:true persistent?:false timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@3c3244b9 initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Wed Apr 15 08:07:20 EDT 2015 timerState=IN_TIMEOUT info=null starting at 9999 milliseconds from now

2015-04-15 08:07:10,001 TRACE [org.jboss.security] (EJB default - 3) PBOX000354: Setting security roles ThreadLocal: {}

2015-04-15 08:07:10,002 TRACE [org.jboss.security] (EJB default - 3) PBOX000354: Setting security roles ThreadLocal: null

[jaikiran]

Based on that log and looking at the server code, I can say 2 things for sure:

1) This call isn't reaching the EJB layer and is instead failing at the web layer

2) There's some extensive magic going on in the role mapping code (within picketbox) which I don't have enough experience with, to understand.

In short, once Undertow (the web layer) authenticates the user, it asks the authorization manager to go fetch the roles for that user. I suspect that's where things go wrong and I think it has to do with the additional layer of role mapping that is happening via the test-authorizations.properties that you have, but I can't be sure of that yet.

The only way, I think, we can know the real issue, is if you can attach a simple application which reproduces this problem and someone from the PicketBox or WildFly AS team or some other volunteer can take a look at it and debug it. I'll give that app a try myself if I find enough time to do so.

[jewellgm]

jaikiran pai wrote:

The only way, I think, we can know the real issue, is if you can attach a simple application which reproduces this problem and someone from the PicketBox or WildFly AS team or some other volunteer can take a look at it and debug it. I'll give that app a try myself if I find enough time to do so.

I created a simple web service that appears to reproduce the issue.  However, apart from the standard "application realm" authentication, I am not doing any processing on it -- no role mapping at all.  Turning on TRACE level logging for the security, ejb3, and undertow subsystems show NO entries in the log file.

Note that if I send in invalid credentials, I receive a "401 unauthorized" error from the server.  If I send in valid credentials, I receive the "403 forbidden" error.  I can display the WSDL by going to the appropriate URL in a browser, though.

If you have time, can you take a look?  It's really a simple app, and maybe is indicative of just something in general that is wrong with how the web service is being deployed.  I don't immediately see how to attach a file to this discussion.  How do I get it to you?

[jaikiran]

Greg Jewell wrote:

  I don't immediately see how to attach a file to this discussion.  How do I get it to you?

In the reply editor, at the top right corner, you'll notice a "Use advanced editor" link. Clicking on that will open up the advanced editor which at the right bottom corner will have the "Attach" option. Use that for attachments to posts.

[jewellgm]

I've attached a zip file containing the source code that I used to create the problem, and the artifacts created from the source. I intentionally am leaving out jars that are needed at compile time to reduce the size of the attachment.  If you want to build this yourself, you'll need the jax-ws reference jars from Oracle, and a few jars from wildfly.  They would need to go into the lib directory.  There's also a README file in the zip that describes how to install it.  It's all pretty straight-forward.  Note that the jar in the ear that's listed as an ejb module should be broken up and have some classes put into a library jar, but I wasn't too worried about it for this test.

I don't know whether this test demonstrates the same problem, or whether the JAAS authentication/authorization issue is different.  I'm hoping it's the same root problem though.

Thank you again for your help!

[jewellgm]

Further experimentation with the sample code revealed that if I comment out the <auth-method>BASIC</auth-method> in jboss-webservices.xml, the invocation worked.  This, of course, isn't an acceptable solution.  Is there some other configuration that I need to set?