Additional lines in logging.properties: org.apache.catalina.authenticator.level=FINE org.apache.catalina.realm.level=FINE catalina.2018-01-23.log: 23-Jan-2018 19:25:01.817 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 574 ms 23-Jan-2018 19:25:05.067 FINE [tc-http-1] org.apache.catalina.authenticator.AuthenticatorBase.invoke Security checking request GET /test/ 23-Jan-2018 19:25:05.067 FINE [tc-http-1] org.apache.catalina.realm.RealmBase.findSecurityConstraints No applicable constraints defined 23-Jan-2018 19:25:05.083 FINE [tc-http-1] org.apache.catalina.authenticator.jaspic.AuthConfigFactoryImpl.loadPersistentRegistrations Loading persistent provider registrations from [D:\Programs\Tomcat for Eclipse\Tomcat_8.5\conf\jaspic-providers.xml] 23-Jan-2018 19:25:05.083 FINE [tc-http-1] org.apache.catalina.authenticator.AuthenticatorBase.invoke Not subject to any constraint 23-Jan-2018 19:25:16.677 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.invoke Security checking request POST /test/login 23-Jan-2018 19:25:16.677 FINE [tc-http-3] org.apache.catalina.realm.RealmBase.findSecurityConstraints No applicable constraints defined 23-Jan-2018 19:25:16.677 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.invoke Not subject to any constraint 23-Jan-2018 19:25:16.677 FINE [tc-http-3] org.apache.catalina.realm.CombinedRealm.authenticate Attempting to authenticate user [testuser] with realm [org.apache.catalina.realm.UserDatabaseRealm] 23-Jan-2018 19:25:16.677 FINE [tc-http-3] org.apache.catalina.realm.CombinedRealm.authenticate Authenticated user [testuser] with realm [org.apache.catalina.realm.UserDatabaseRealm] 23-Jan-2018 19:25:16.677 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.register Authenticated 'testuser' with type 'NONE' 23-Jan-2018 19:25:16.677 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.register Session ID changed on authentication from [9758C5AF239B650A40DE66DEF46012B6] to [F41141C4E82AC7F7BCC5A41C684E2B7D] 23-Jan-2018 19:25:27.037 FINE [tc-http-1] org.apache.catalina.authenticator.AuthenticatorBase.invoke Security checking request GET /test/authtest 23-Jan-2018 19:25:27.037 FINE [tc-http-1] org.apache.catalina.authenticator.AuthenticatorBase.invoke We have cached auth type NONE for principal GenericPrincipal[testuser(testrole,)] 23-Jan-2018 19:25:27.037 FINE [tc-http-1] org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking constraint 'SecurityConstraint[null]' against GET /authtest --> true 23-Jan-2018 19:25:27.037 FINE [tc-http-1] org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling hasUserDataPermission() 23-Jan-2018 19:25:27.037 FINE [tc-http-1] org.apache.catalina.realm.RealmBase.hasUserDataPermission User data constraint has no restrictions 23-Jan-2018 19:25:27.037 FINE [tc-http-1] org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling authenticate() 23-Jan-2018 19:25:27.053 FINE [tc-http-1] org.apache.catalina.authenticator.AuthenticatorBase.checkForCachedAuthentication Already authenticated [testuser] 23-Jan-2018 19:25:27.053 FINE [tc-http-1] org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling accessControl() 23-Jan-2018 19:25:27.053 FINE [tc-http-1] org.apache.catalina.realm.RealmBase.hasResourcePermission Checking roles GenericPrincipal[testuser(testrole,)] 23-Jan-2018 19:25:27.053 FINE [tc-http-1] org.apache.catalina.realm.RealmBase.hasRole Username [testuser] has role [testrole] 23-Jan-2018 19:25:27.053 FINE [tc-http-1] org.apache.catalina.realm.RealmBase.hasResourcePermission Role found: testrole 23-Jan-2018 19:25:27.053 FINE [tc-http-1] org.apache.catalina.authenticator.AuthenticatorBase.invoke Successfully passed all security constraints 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.invoke Security checking request GET /test/authtest 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.invoke We have cached auth type NONE for principal User username="testuser", roles="testrole" 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking constraint 'SecurityConstraint[null]' against GET /authtest --> true 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling hasUserDataPermission() 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.realm.RealmBase.hasUserDataPermission User data constraint has no restrictions 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling authenticate() 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.checkForCachedAuthentication Already authenticated [testuser] 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling accessControl() 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.realm.RealmBase.hasResourcePermission Checking roles User username="testuser", roles="testrole" 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.realm.RealmBase.hasRole Username [testuser] does NOT have role [testrole] 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.realm.RealmBase.hasResourcePermission No role found: testrole 23-Jan-2018 19:25:35.225 FINE [tc-http-3] org.apache.catalina.authenticator.AuthenticatorBase.invoke Failed accessControl() test Access Log, configured with pattern="%a (%{X-Forwarded-For}i) %l %u %t "%r" %s %b (%D ms) [%{org.apache.catalina.parameter_parse_failed}r %{org.apache.catalina.parameter_parse_failed_reason}r] [%I]" 127.0.0.1 (-) - - [23/Jan/2018:19:25:05 +0300] "GET /test/ HTTP/1.1" 200 2829 (516 ms) [- -] [tc-http-1] 127.0.0.1 (-) - testuser [23/Jan/2018:19:25:16 +0300] "POST /test/login HTTP/1.1" 200 41 (0 ms) [- -] [tc-http-3] 127.0.0.1 (-) - testuser [23/Jan/2018:19:25:27 +0300] "GET /test/authtest HTTP/1.1" 200 50 (16 ms) [- -] [tc-http-1] 127.0.0.1 (-) - testuser [23/Jan/2018:19:25:35 +0300] "GET /test/authtest HTTP/1.1" 403 16 (16 ms) [- -] [tc-http-3]