You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Graham Leggett <mi...@sharp.fm> on 2015/03/13 20:02:14 UTC

Tomcat7: debugging realms - a howto?

Hi all,

I have a working realm installation using basic authentication, which I need to switch to client certificate authentication. Having done so it doesn’t work, I just get “forbidden”, with no indication of the error involved.

Back in the day there was a simple “debug” flag that turned on debugging. That seems to have been replaced with the significantly more complicated java.util.logging implementation, based on adding a logging.properties file. Adding this file, along with suggested entries to debug realms has had no effect, I can still see nothing in console.out.

Can anyone point at a simple, clear and unambiguous set of instructions that indicate how to debug a realm configuration?

I have tomcat up and running in a debugger, if the realm logging is broken is there a suggested point in the code I should be placing a breakpoint so I can step through this?

Regards,
Graham
—


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat7: debugging realms - a howto?

Posted by Konstantin Kolinko <kn...@gmail.com>.
2015-03-13 22:02 GMT+03:00 Graham Leggett <mi...@sharp.fm>:
> Hi all,
>
> I have a working realm installation using basic authentication, which I need to switch to client certificate authentication. Having done so it doesn’t work, I just get “forbidden”, with no indication of the error involved.
>
> Back in the day there was a simple “debug” flag that turned on debugging. That seems to have been replaced with the significantly more complicated java.util.logging implementation, based on adding a logging.properties file. Adding this file, along with suggested entries to debug realms has had no effect, I can still see nothing in console.out.
>
> Can anyone point at a simple, clear and unambiguous set of instructions that indicate how to debug a realm configuration?
>
> I have tomcat up and running in a debugger, if the realm logging is broken is there a suggested point in the code I should be placing a breakpoint so I can step through this?


A realm is a "database" used by an authenticator.
The BASIC authentication is implemented by BasicAuthenticator. I would
recommend to start debugging with that authenticator class.

An authenticator is essentially a Valve. Its entry point is invoke() method.

Best regards,
Konstantin Kolinko

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat7: debugging realms - a howto?

Posted by Neven Cvetkovic <ne...@gmail.com>.
Graham,

On Fri, Mar 13, 2015 at 4:43 PM, Graham Leggett <mi...@sharp.fm> wrote:

> On 13 Mar 2015, at 9:58 PM, Neven Cvetkovic <ne...@gmail.com>
> wrote:
>
> > Just to confirm, the 403 Forbidden page was rendered by Tomcat, not
> Apache
> > HTTPD?
>
> Yes, it is branded tomcat and appears in the tomcat access log.


Great. We know it is Tomcat rendering this page.


> >
> > Next thing I would probably increase the verbosity of the Realm logging,
> by
> > updating your conf/logging.properties, e.g.
> > org.apache.catalina.realm.level = ALL
> > org.apache.catalina.realm.useParentHandlers = true
> > org.apache.catalina.authenticator.level = ALL
> > org.apache.catalina.authenticator.useParentHandlers = true
> >
> >
> > You might want to disable buffering as well, e.g.
> > 1catalina.org.apache.juli.FileHandler.bufferSize = -1
>
> None of these changes to logging.properties have any effect on my test
> system of tomcat v7.0.59 deployed to RHEL6. I get no changes to
> catalina.out at all, it stays completely silent.
>
> Sorry, I think we forgot to include the ConsoleHandler and FileHandlers to
collect ALL logs, not just FINE level (out-of-box level), e.g.

1catalina.org.apache.juli.FileHandler.level = ALL
1catalina.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
1catalina.org.apache.juli.FileHandler.prefix = catalina.
1catalina.org.apache.juli.FileHandler.bufferSize = -1

java.util.logging.ConsoleHandler.level = ALL
java.util.logging.ConsoleHandler.formatter =
java.util.logging.SimpleFormatter

Also, try to switch over to the old system quickly (where things were
working properly), and try to input a wrong username, or a user that has
proper password, but not the appropriate role. Let's see if the
authorization error (403) shows up now in the logs.

I will test this on my Tomcat with DataSourceRealm. I've got it to log with
my out-of-box UserDatabaseRealm, e.g.

Mar 13, 2015 5:36:56 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE: Security checking request GET /SimpleAppAuth/time
Mar 13, 2015 5:36:56 PM org.apache.catalina.realm.RealmBase
findSecurityConstraints
FINE:   Checking constraint 'SecurityConstraint[SecurePages]' against GET
/time --> true
Mar 13, 2015 5:36:56 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling hasUserDataPermission()
Mar 13, 2015 5:36:56 PM org.apache.catalina.realm.RealmBase
hasUserDataPermission
FINE:   User data constraint has no restrictions
Mar 13, 2015 5:36:56 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling authenticate()
Mar 13, 2015 5:36:56 PM org.apache.catalina.realm.CombinedRealm authenticate
FINE: Attempting to authenticate user "john" with realm
"org.apache.catalina.realm.UserDatabaseRealm/1.0"
Mar 13, 2015 5:36:56 PM org.apache.catalina.realm.CombinedRealm authenticate
FINE: Authenticated user "john" with realm
"org.apache.catalina.realm.UserDatabaseRealm/1.0"
Mar 13, 2015 5:36:56 PM org.apache.catalina.authenticator.AuthenticatorBase
register
FINE: Authenticated 'john' with type 'BASIC'
Mar 13, 2015 5:36:56 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling accessControl()
Mar 13, 2015 5:36:56 PM org.apache.catalina.realm.RealmBase
hasResourcePermission
FINE:   Checking roles GenericPrincipal[john(APP_USER,)]
Mar 13, 2015 5:36:56 PM org.apache.catalina.realm.RealmBase hasRole
FINE: Username john does NOT have role APP_ADMIN
Mar 13, 2015 5:36:56 PM org.apache.catalina.realm.RealmBase
hasResourcePermission
FINE: No role found:  APP_ADMIN
Mar 13, 2015 5:36:56 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Failed accessControl() test

Hopefully, once we get the logging working - it will give us ideas why you
got 403.

I tried to make the same changes to a tomcat v7.0.59 running within
> Eclipse, and in this case I get the following:
>
> Can't load log handler "2localhost.org.apache.juli.FileHandler"
> java.lang.ClassNotFoundException: 2localhost.org.apache.juli.FileHandler
> java.lang.ClassNotFoundException: 2localhost.org.apache.juli.FileHandler
>         at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
>         at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
>         at java.lang.ClassLoader.loadClass(ClassLoader.java:423)
>         at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)
>         at java.lang.ClassLoader.loadClass(ClassLoader.java:356)
>         at java.util.logging.LogManager$3.run(LogManager.java:418)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at
> java.util.logging.LogManager.loadLoggerHandlers(LogManager.java:405)
>         at java.util.logging.LogManager.addLogger(LogManager.java:609)
>         at java.util.logging.LogManager.demandLogger(LogManager.java:355)
>         at java.util.logging.Logger.getLogger(Logger.java:328)
>         at
> org.apache.juli.logging.DirectJDKLog.<init>(DirectJDKLog.java:71)
>         at
> org.apache.juli.logging.DirectJDKLog.getInstance(DirectJDKLog.java:196)
>         at
> org.apache.juli.logging.LogFactory.getInstance(LogFactory.java:170)
>         at org.apache.juli.logging.LogFactory.getLog(LogFactory.java:311)
>         at
> org.apache.catalina.core.ContainerBase.getLogger(ContainerBase.java:452)
>         at
> org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:1102)
>         at
> org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:816)
>         at
> org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
>         at
> org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1575)
>         at
> org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1565)
>         at
> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>         at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
>         at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
>         at java.lang.Thread.run(Thread.java:722)
>

That's strange. Which logging.properties file did you change? What specific
changes did you make to the logging.properties file? How did you configure
Tomcat logging? Getting it to work with Eclipse is a bit tricky, you need
to configure the launch configuration.

You can always look at jvisualvm or jconsole (programs that come with JDK),
to see exactly the JVM arguments that were passed in, and other useful
stuff (MBeans, runtime configuration, threads, etc...)

For example,

If you were running Tomcat as a standalone, it would be something along the
lines:
-Djava.util.logging.config.file=/d/servers/apache-tomcat-7.0.59/conf/logging.properties
-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
-Djava.endorsed.dirs=/d/servers/apache-tomcat-7.0.59/endorsed
-Dcatalina.base=/d/servers/apache-tomcat-7.0.59
-Dcatalina.home=/d/servers/apache-tomcat-7.0.59
-Djava.io.tmpdir=/d/servers/apache-tomcat-7.0.59/temp

If you were running it from Eclipse, it would be something along the lines:
-Dcatalina.base=/d/servers/apache-tomcat-7.0.59
-Dcatalina.home=/d/servers/apache-tomcat-7.0.59
-Dwtp.deploy=/d/servers/apache-tomcat-7.0.59/wtpwebapps
-Djava.endorsed.dirs=/d/servers/apache-tomcat-7.0.59/endorsed
-Dfile.encoding=UTF-8

Notice, Eclipse launch configuration doesn't have
java.util.logging.config.file defined out of box, so the only out-of-box
log file created - would be the AccessLogValve
localhost_access_log.xxxx-xx-xx.txt file. That might differ on different
platforms.
- Remove all log files - or better yet - place them in a new directory.
- Do a fresh start of Tomcat from Eclipse, and see if your
catalina.XXXX-XX-XX.log gets generated. Just to make sure it is Eclipse
startup that generates them, not the other server.
- Even better, if you have them installed in different folders, so you are
not mixing the two :)


Further on, the following is logged, which suggests that there is no roles
> defined at all:
>
> Mar 13, 2015 10:13:12 PM
> org.apache.catalina.authenticator.AuthenticatorBase invoke
> FINE: Security checking request GET /
> Mar 13, 2015 10:13:12 PM
> org.apache.catalina.authenticator.AuthenticatorBase invoke
> FINE: Security checking request GET /
> Mar 13, 2015 10:13:12 PM org.apache.catalina.realm.RealmBase
> findSecurityConstraints
> FINE:   No applicable constraints defined
> Mar 13, 2015 10:13:12 PM org.apache.catalina.realm.RealmBase
> findSecurityConstraints
> FINE:   No applicable constraints defined
> Mar 13, 2015 10:13:12 PM
> org.apache.catalina.authenticator.AuthenticatorBase invoke
> FINE:  Not subject to any constraint
> Mar 13, 2015 10:13:12 PM
> org.apache.catalina.authenticator.AuthenticatorBase invoke
> FINE:  Not subject to any constraint
>
>
Did this log show up before you made a change or after you made a change to
logging.properties?

It seems you do have some logging setup, e.g.
"org.apache.catalina.realm.RealmBase" and
"org.apache.catalina.authenticator.AuthenticatorBase".

What these messages are telling you is that "/" (default page) is not
subject to any constraints. Your web.xml does not require the
authentication/authorization. See my examples below.


None of this is making any sense. Is there no simply way of switching on
> realm debugging as we used to with the “debug” attribute?
>
>
I know, it is a bit cryptic. But we will get to the bottom of it.

About logging - the idea is to change logging levels in the
logging.properties, so we would know more about what's going on in the
background.

I would probably get the logging done first, move it to the old
DataSourceRealm, make sure you get AuthenticatorBase and RealmBase to log
stuff, both errors and successes.

Here are type of things I would expect to see in the logfile:

(1) When requesting a non-secured page, e.g.
http://localhost:8080/SimpleAppAuth/
Mar 13, 2015 6:30:03 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE: Security checking request GET /SimpleAppAuth/
Mar 13, 2015 6:30:03 PM org.apache.catalina.realm.RealmBase
findSecurityConstraints
FINE:   Checking constraint 'SecurityConstraint[SecurePages]' against GET
//WEB-INF/views/home.jsp --> false
Mar 13, 2015 6:30:03 PM org.apache.catalina.realm.RealmBase
findSecurityConstraints
FINE:   Checking constraint 'SecurityConstraint[SecurePages]' against GET
//WEB-INF/views/home.jsp --> false
Mar 13, 2015 6:30:03 PM org.apache.catalina.realm.RealmBase
findSecurityConstraints
FINE:   Checking constraint 'SecurityConstraint[SecurePages]' against GET
//WEB-INF/views/home.jsp --> false
Mar 13, 2015 6:30:03 PM org.apache.catalina.realm.RealmBase
findSecurityConstraints
FINE:   Checking constraint 'SecurityConstraint[SecurePages]' against GET
//WEB-INF/views/home.jsp --> false
Mar 13, 2015 6:30:03 PM org.apache.catalina.realm.RealmBase
findSecurityConstraints
FINE:   No applicable constraint located
Mar 13, 2015 6:30:03 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Not subject to any constraint

(2) When requesting a secured page, e.g.
http://localhost:8080/SimpleAppAuth/time
Mar 13, 2015 6:30:19 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE: Security checking request GET /SimpleAppAuth/time
Mar 13, 2015 6:30:19 PM org.apache.catalina.realm.RealmBase
findSecurityConstraints
FINE:   Checking constraint 'SecurityConstraint[SecurePages]' against GET
/time --> true
Mar 13, 2015 6:30:19 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling hasUserDataPermission()
Mar 13, 2015 6:30:19 PM org.apache.catalina.realm.RealmBase
hasUserDataPermission
FINE:   User data constraint has no restrictions
Mar 13, 2015 6:30:19 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling authenticate()
Mar 13, 2015 6:30:19 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Failed authenticate() test

(3) When trying to login user with their incorrect password, e.g.
john/incorrectpassword
Mar 13, 2015 6:30:26 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE: Security checking request GET /SimpleAppAuth/time
Mar 13, 2015 6:30:26 PM org.apache.catalina.realm.RealmBase
findSecurityConstraints
FINE:   Checking constraint 'SecurityConstraint[SecurePages]' against GET
/time --> true
Mar 13, 2015 6:30:26 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling hasUserDataPermission()
Mar 13, 2015 6:30:26 PM org.apache.catalina.realm.RealmBase
hasUserDataPermission
FINE:   User data constraint has no restrictions
Mar 13, 2015 6:30:26 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling authenticate()
Mar 13, 2015 6:30:26 PM org.apache.catalina.realm.CombinedRealm authenticate
FINE: Attempting to authenticate user "john" with realm
"org.apache.catalina.realm.UserDatabaseRealm/1.0"
Mar 13, 2015 6:30:26 PM org.apache.catalina.realm.CombinedRealm authenticate
FINE: combinedRealm.authFail
Mar 13, 2015 6:30:26 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Failed authenticate() test


(4) When trying to login user with their proper password, e.g.
jane/correctpassword (200)
Mar 13, 2015 6:31:28 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE: Security checking request GET /SimpleAppAuth/time
Mar 13, 2015 6:31:28 PM org.apache.catalina.realm.RealmBase
findSecurityConstraints
FINE:   Checking constraint 'SecurityConstraint[SecurePages]' against GET
/time --> true
Mar 13, 2015 6:31:28 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling hasUserDataPermission()
Mar 13, 2015 6:31:28 PM org.apache.catalina.realm.RealmBase
hasUserDataPermission
FINE:   User data constraint has no restrictions
Mar 13, 2015 6:31:28 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling authenticate()
Mar 13, 2015 6:31:28 PM org.apache.catalina.realm.CombinedRealm authenticate
FINE: Attempting to authenticate user "jane" with realm
"org.apache.catalina.realm.UserDatabaseRealm/1.0"
Mar 13, 2015 6:31:28 PM org.apache.catalina.realm.CombinedRealm authenticate
FINE: Authenticated user "jane" with realm
"org.apache.catalina.realm.UserDatabaseRealm/1.0"
Mar 13, 2015 6:31:28 PM org.apache.catalina.authenticator.AuthenticatorBase
register
FINE: Authenticated 'jane' with type 'BASIC'
Mar 13, 2015 6:31:28 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Calling accessControl()
Mar 13, 2015 6:31:28 PM org.apache.catalina.realm.RealmBase
hasResourcePermission
FINE:   Checking roles GenericPrincipal[jane(APP_ADMIN,APP_USER,)]
Mar 13, 2015 6:31:28 PM org.apache.catalina.realm.RealmBase hasRole
FINE: Username jane has role APP_ADMIN
Mar 13, 2015 6:31:28 PM org.apache.catalina.realm.RealmBase
hasResourcePermission
FINE: Role found:  APP_ADMIN
Mar 13, 2015 6:31:28 PM org.apache.catalina.authenticator.AuthenticatorBase
invoke
FINE:  Successfully passed all security constraints

Hope that gives you some ammunition.

I will see to setup a quick DataSourceRealm on my box, so I can get to the
bottom of it.

It is a very interesting problem to solve!

Thanks,
Neven

Re: Tomcat7: debugging realms - a howto?

Posted by Graham Leggett <mi...@sharp.fm>.
On 14 Mar 2015, at 3:43 PM, Graham Leggett <mi...@sharp.fm> wrote:

> Changing the auth-type to CLIENT-CERT shows that the username has been replaced by the subject-DN of the cert, which is progress.

Reverse engineering tomcat showed that the tomcatAuthentication parameter solved half the problem - when the webserver provided REMOTE_USER, this was used as the principal in the request, but as a side effect the role lookup was bypassed, and any web application using roles stopped working.

The attached patches for tomcat v7.0.x, tomcat v8.0.x and tomcat 9.0.x introduce the tomcatAuthorization flag:

https://bz.apache.org/bugzilla/show_bug.cgi?id=57708

The tomcatAuthorization flag, when true, takes the REMOTE_USER from the webserver, but ensures that all the role lookups occur as normal.

This means you can drop in a webserver in front of a tomcat hosted web application, and automatically the authn of the webserver will replace the authn in the web application, leaving the authz intact and working.

This solves my problem.

Regards,
Graham
—


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat7: debugging realms - a howto?

Posted by Graham Leggett <mi...@sharp.fm>.
On 14 Mar 2015, at 1:04 AM, Konstantin Kolinko <kn...@gmail.com> wrote:

> You are using JRE's default java.util.logging.LogManager.
> 
> You need to configure JRE to use the Tomcat JULI implementation of log
> manager with
> -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
> 
> The JRE class is usable, but its logging.properties format is a bit different.

Adding the above to Eclipse’s launcher configuration brought sanity back to the logging.

What this revealed was that no realm decisions were being made - we weren’t getting that far.

Placing a watchpoint on the “status” variable in the response revealed the point at which we were getting the 403.

In my case switching from basic auth to cert meant changing the tomcat protocol from HTTP to AJP, and this in turn caused a org.apache.catalina.valves.RemoteAddrValve configuration to kick in, which now no longer pointed at localhost (address of Apache proxy) but rather the browser IP, thanks to AJP:

    <Valve className="org.apache.catalina.valves.RemoteAddrValve"
        allow="127.0.0.1”/>

Stepping through the org.apache.catalina.valves.RemoteAddrValve implementation in the debugger showed that when it returned the 403, it logged nothing in the log, and it returned no explanatory message in the response. Ideally this needs to be fixed: https://bz.apache.org/bugzilla/show_bug.cgi?id=57705

Now I get the basic authentication to hit as normal.

Changing the auth-type to CLIENT-CERT shows that the username has been replaced by the subject-DN of the cert, which is progress.

Regards,
Graham
—


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat7: debugging realms - a howto?

Posted by Konstantin Kolinko <kn...@gmail.com>.
2015-03-13 23:43 GMT+03:00 Graham Leggett <mi...@sharp.fm>:
> On 13 Mar 2015, at 9:58 PM, Neven Cvetkovic <ne...@gmail.com> wrote:
>
>> Just to confirm, the 403 Forbidden page was rendered by Tomcat, not Apache
>> HTTPD?
>
> Yes, it is branded tomcat and appears in the tomcat access log.
>
>> I don't expect it is an Apache issue here - because you mentioned your
>> application worked before - I assume with the same URL, and no updates to
>> Apache HTTPD configuration.
>>
>> Next thing I would probably increase the verbosity of the Realm logging, by
>> updating your conf/logging.properties, e.g.
>> org.apache.catalina.realm.level = ALL
>> org.apache.catalina.realm.useParentHandlers = true
>> org.apache.catalina.authenticator.level = ALL
>> org.apache.catalina.authenticator.useParentHandlers = true
>>
>>
>> You might want to disable buffering as well, e.g.
>> 1catalina.org.apache.juli.FileHandler.bufferSize = -1
>
> None of these changes to logging.properties have any effect on my test system of tomcat v7.0.59 deployed to RHEL6. I get no changes to catalina.out at all, it stays completely silent.
>
> I tried to make the same changes to a tomcat v7.0.59 running within Eclipse, and in this case I get the following:
>
> Can't load log handler "2localhost.org.apache.juli.FileHandler"
> java.lang.ClassNotFoundException: 2localhost.org.apache.juli.FileHandler
> java.lang.ClassNotFoundException: 2localhost.org.apache.juli.FileHandler
>         at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
>         at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
>         at java.security.AccessController.doPrivileged(Native Method)
>         at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
>         at java.lang.ClassLoader.loadClass(ClassLoader.java:423)
>         at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)
>         at java.lang.ClassLoader.loadClass(ClassLoader.java:356)
>         at java.util.logging.LogManager$3.run(LogManager.java:418)

You are using JRE's default java.util.logging.LogManager.

You need to configure JRE to use the Tomcat JULI implementation of log
manager with
-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager

The JRE class is usable, but its logging.properties format is a bit different.


Best regards,
Konstantin Kolinko

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat7: debugging realms - a howto?

Posted by Graham Leggett <mi...@sharp.fm>.
On 13 Mar 2015, at 9:58 PM, Neven Cvetkovic <ne...@gmail.com> wrote:

> Just to confirm, the 403 Forbidden page was rendered by Tomcat, not Apache
> HTTPD?

Yes, it is branded tomcat and appears in the tomcat access log.

> I don't expect it is an Apache issue here - because you mentioned your
> application worked before - I assume with the same URL, and no updates to
> Apache HTTPD configuration.
> 
> Next thing I would probably increase the verbosity of the Realm logging, by
> updating your conf/logging.properties, e.g.
> org.apache.catalina.realm.level = ALL
> org.apache.catalina.realm.useParentHandlers = true
> org.apache.catalina.authenticator.level = ALL
> org.apache.catalina.authenticator.useParentHandlers = true
> 
> 
> You might want to disable buffering as well, e.g.
> 1catalina.org.apache.juli.FileHandler.bufferSize = -1

None of these changes to logging.properties have any effect on my test system of tomcat v7.0.59 deployed to RHEL6. I get no changes to catalina.out at all, it stays completely silent.

I tried to make the same changes to a tomcat v7.0.59 running within Eclipse, and in this case I get the following:

Can't load log handler "2localhost.org.apache.juli.FileHandler"
java.lang.ClassNotFoundException: 2localhost.org.apache.juli.FileHandler
java.lang.ClassNotFoundException: 2localhost.org.apache.juli.FileHandler
	at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
	at java.net.URLClassLoader$1.run(URLClassLoader.java:355)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.net.URLClassLoader.findClass(URLClassLoader.java:354)
	at java.lang.ClassLoader.loadClass(ClassLoader.java:423)
	at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)
	at java.lang.ClassLoader.loadClass(ClassLoader.java:356)
	at java.util.logging.LogManager$3.run(LogManager.java:418)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.util.logging.LogManager.loadLoggerHandlers(LogManager.java:405)
	at java.util.logging.LogManager.addLogger(LogManager.java:609)
	at java.util.logging.LogManager.demandLogger(LogManager.java:355)
	at java.util.logging.Logger.getLogger(Logger.java:328)
	at org.apache.juli.logging.DirectJDKLog.<init>(DirectJDKLog.java:71)
	at org.apache.juli.logging.DirectJDKLog.getInstance(DirectJDKLog.java:196)
	at org.apache.juli.logging.LogFactory.getInstance(LogFactory.java:170)
	at org.apache.juli.logging.LogFactory.getLog(LogFactory.java:311)
	at org.apache.catalina.core.ContainerBase.getLogger(ContainerBase.java:452)
	at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:1102)
	at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:816)
	at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1575)
	at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1565)
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
	at java.lang.Thread.run(Thread.java:722)

Further on, the following is logged, which suggests that there is no roles defined at all:

Mar 13, 2015 10:13:12 PM org.apache.catalina.authenticator.AuthenticatorBase invoke
FINE: Security checking request GET /
Mar 13, 2015 10:13:12 PM org.apache.catalina.authenticator.AuthenticatorBase invoke
FINE: Security checking request GET /
Mar 13, 2015 10:13:12 PM org.apache.catalina.realm.RealmBase findSecurityConstraints
FINE:   No applicable constraints defined
Mar 13, 2015 10:13:12 PM org.apache.catalina.realm.RealmBase findSecurityConstraints
FINE:   No applicable constraints defined
Mar 13, 2015 10:13:12 PM org.apache.catalina.authenticator.AuthenticatorBase invoke
FINE:  Not subject to any constraint
Mar 13, 2015 10:13:12 PM org.apache.catalina.authenticator.AuthenticatorBase invoke
FINE:  Not subject to any constraint

None of this is making any sense. Is there no simply way of switching on realm debugging as we used to with the “debug” attribute?

Regards,
Graham
—


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: Tomcat7: debugging realms - a howto?

Posted by Neven Cvetkovic <ne...@gmail.com>.
Graham,

On Fri, Mar 13, 2015 at 3:02 PM, Graham Leggett <mi...@sharp.fm> wrote:

> Hi all,
>
> I have a working realm installation using basic authentication, which I
> need to switch to client certificate authentication. Having done so it
> doesn’t work, I just get “forbidden”, with no indication of the error
> involved.
>

Just to confirm, the 403 Forbidden page was rendered by Tomcat, not Apache
HTTPD?
I don't expect it is an Apache issue here - because you mentioned your
application worked before - I assume with the same URL, and no updates to
Apache HTTPD configuration.

Next thing I would probably increase the verbosity of the Realm logging, by
updating your conf/logging.properties, e.g.
org.apache.catalina.realm.level = ALL
org.apache.catalina.realm.useParentHandlers = true
org.apache.catalina.authenticator.level = ALL
org.apache.catalina.authenticator.useParentHandlers = true


You might want to disable buffering as well, e.g.
1catalina.org.apache.juli.FileHandler.bufferSize = -1

Hope that helps!

Cheers!
Neven