Tomcat version: 8.5.14
OS: debian 9 (stretch)
Issues: If using SSLVerifyClient=optional, it seems to work (log attached,
assuming config is validated);
however when trying to use SSLVerifyClient=none, the browser complains
This site can’t provide a secure connection login-test.foo.com sent an
invalid response.
ERR_SSL_PROTOCOL_ERROR
When digging into tomcat log, the only clues as follows.
28-Aug-2019 18:16:38.090 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling
authenticate()
28-Aug-2019 18:16:38.091 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Failed
authenticate() test
.. wondering if anyone has any suggestion as how to debug the issues.
Thank you all in advance for your help.
Configuration:
1. web.xml
<!-- Servlet protected by container used for X.509 authentication -->
<servlet>
<servlet-name>X509AuthHandler</servlet-name>
<servlet-class>net.shibboleth.idp.authn.impl.X509AuthServlet</servlet-class>
<load-on-startup>3</load-on-startup>
</servlet>
<servlet-mapping>
<servlet-name>X509AuthHandler</servlet-name>
<url-pattern>/Authn/X509</url-pattern>
</servlet-mapping>
<security-constraint>
<web-resource-collection>
<web-resource-name>X509AuthHandler</web-resource-name>
<url-pattern>/Authn/X509</url-pattern>
</web-resource-collection>
<user-data-constraint>
<transport-guarantee>CONFIDENTIAL</transport-guarantee>
</user-data-constraint>
<auth-constraint>
<role-name>X509</role-name>
</auth-constraint>
</security-constraint>
<login-config>
<auth-method>CLIENT-CERT</auth-method>
</login-config>
2. server.xml
<Service name="Catalina">
<Connector port="8443"
protocol="org.apache.coyote.http11.Http11AprProtocol"
SSLEnabled="true"
scheme="https"
secure="true"
maxPostSize="100000"
SSLCertificateFile="/etc/ssl/certs/server.pem"
SSLCertificateChainFile="/etc/ssl/certs/server-chain.pem"
SSLCertificateKeyFile="/etc/ssl/private/server.key"
SSLCACertificateFile="/etc/ssl/certs/ca-client.pem"
SSLVerifyClient="none"
SSLProtocol="TLSv1.2+TLSv1.1"
SSLCipherSuite="ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256"
SSLHonorCipherOrder="on" />
<Engine name="Catalina"
defaultHost="login-test.foo.com">
<Realm className="org.apache.catalina.realm.CombinedRealm" >
<Realm
className="net.unicon.tomcat7.realm.X509AuthenticationBypassingRealm"/>
</Realm>
3. logging.properties
org.apache.catalina.realm.level = ALL
org.apache.catalina.realm.useParentHandlers = true
org.apache.catalina.authenticator.level = ALL
org.apache.catalina.authenticator.useParentHandlers = true
net.unicon.tomcat7.realm.level = ALL
net.unicon.tomcat7.realm.useParentHandlers = true
org.apache.coyote.http11.level = ALL
org.apache.coyote.http11.useParentHandlers = true
with -Djavax.net.debug=ssl
4. When SSLVerifyClient=none is specified in Connector, got the following
in the browser,
This site can’t provide a secure connection login-test.foo.com sent an
invalid response.
ERR_SSL_PROTOCOL_ERROR
and in the catalina log,
28-Aug-2019 18:16:38.089 FINE [https-openssl-apr-8443-exec-1]
org.apache.coyote.http11.Http11InputBuffer.parseRequestLine Received [GET
/idp/Authn/X509?conversation=e1s1 HTTP/1.1
Host: login-test.foo.com
Connection: keep-alive
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/76.0.3809.100 Safari/537.36
Sec-Fetch-Mode: navigate
Sec-Fetch-User: ?1
DNT: 1
Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3
Sec-Fetch-Site: none
Accept-Encoding: gzip, deflate, br
Accept-Language: en-US,en;q=0.9,zh-CN;q=0.8,zh;q=0.7,mt;q=0.6,zh-TW;q=0.5
Cookie: JSESSIONID=70B72EE82D09700707565E884DB1E3C5.jvm1; x509passthrough=1
]
28-Aug-2019 18:16:38.090 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Security
checking request GET /idp/Authn/X509
28-Aug-2019 18:16:38.090 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking
constraint 'SecurityConstraint[X509AuthHandler]' against GET /Authn/X509
--> true
28-Aug-2019 18:16:38.090 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking
constraint 'SecurityConstraint[Automatic Forward to HTTPS/SSL]' against GET
/Authn/X509 --> true
28-Aug-2019 18:16:38.090 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling
hasUserDataPermission()
28-Aug-2019 18:16:38.090 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.hasUserDataPermission User data
constraint already satisfied
28-Aug-2019 18:16:38.090 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling
authenticate()
28-Aug-2019 18:16:38.091 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Failed
authenticate() test
28-Aug-2019 18:16:38.094 FINE [https-openssl-apr-8443-exec-1]
org.apache.coyote.AbstractProcessorLight.process Socket:
[org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@2081420c:139711359418528],
Status in: [OPEN_READ], State out: [OPEN]
28-Aug-2019 18:16:38.094 FINE [https-openssl-apr-8443-exec-1]
org.apache.coyote.AbstractProtocol$ConnectionHandler.release Pushed
Processor [org.apache.coyote.http11.Http11Processor@4c325234]
28-Aug-2019 18:16:38.115 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Processing
socket [139,711,359,418,528] with status [OPEN_READ]
28-Aug-2019 18:16:38.115 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Found
processor [null] for socket [139,711,359,418,528]
28-Aug-2019 18:16:38.115 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Popped
processor [org.apache.coyote.http11.Http11Processor@4c325234] from cache
28-Aug-2019 18:16:38.124 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.http11.Http11Processor.service Error parsing HTTP request
header
java.io.IOException: Unexpected error [20,014] reading data from the
APR/native socket [139,711,359,418,528] with wrapper
[org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@2081420c
:139711359418528].
at
org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper.fillReadBuffer(AprEndpoint.java:2487)
at
org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper.fillReadBuffer(AprEndpoint.java:2407)
at
org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper.read(AprEndpoint.java:2393)
at
org.apache.coyote.http11.Http11InputBuffer.fill(Http11InputBuffer.java:713)
at
org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:362)
at
org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:683)
at
org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)
at
org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:861)
at
org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.doRun(AprEndpoint.java:2298)
at
org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)
28-Aug-2019 18:16:38.125 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.AbstractProcessorLight.process Socket:
[org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@2081420c:139711359418528],
Status in: [OPEN_READ], State out: [CLOSED]
28-Aug-2019 18:16:38.125 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.AbstractProtocol$ConnectionHandler.release Pushed
Processor [org.apache.coyote.http11.Http11Processor@4c325234]
28-Aug-2019 18:16:40.713 FINE [https-openssl-apr-8443-exec-3]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Processing
socket [139,711,359,279,264] with status [OPEN_READ]
28-Aug-2019 18:16:40.713 FINE [https-openssl-apr-8443-exec-3]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Found
processor [null] for socket [139,711,359,279,264]
28-Aug-2019 18:16:40.713 FINE [https-openssl-apr-8443-exec-3]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Popped
processor [org.apache.coyote.http11.Http11Processor@4c325234] from cache
5. When SSLVerifyClient=optional is specified in Connector, the browser
popped the diag for certificate and all goes well.
27-Aug-2019 03:11:31.248 FINE [https-openssl-apr-8443-exec-1]
org.apache.coyote.http11.Http11InputBuffer.parseRequestLine Received [GET
/idp/Authn/X509?conversation=e1s1 HTTP/1.1
Host: login-test.foo.com
Connection: keep-alive
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/76.0.3809.100 Safari/537.36
Sec-Fetch-Mode: navigate
DNT: 1
Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3
Sec-Fetch-Site: none
Accept-Encoding: gzip, deflate, br
Accept-Language: en-US,en;q=0.9,zh-CN;q=0.8,zh;q=0.7,mt;q=0.6,zh-TW;q=0.5
Cookie: JSESSIONID=88DEB8C5AA0019057B9F65F600CC34DC.jvm1; x509passthrough=1
]
27-Aug-2019 03:11:31.249 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Security
checking request GET /idp/Authn/X509
27-Aug-2019 03:11:31.249 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking
constraint 'SecurityConstraint[X509AuthHandler]' against GET /Authn/X509
--> true
27-Aug-2019 03:11:31.250 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking
constraint 'SecurityConstraint[Automatic Forward to HTTPS/SSL]' against GET
/Authn/X509 --> true
27-Aug-2019 03:11:31.250 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling
hasUserDataPermission()
27-Aug-2019 03:11:31.250 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.hasUserDataPermission User data
constraint already satisfied
27-Aug-2019 03:11:31.250 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling
authenticate()
27-Aug-2019 03:11:31.252 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.CombinedRealm.authenticate Attempting to
authenticate user "T=Apple Inc. Mac OS X (10.13), C=US, OU=MyDevices,
O=Foo, CN=user-foo/Enrollment-XXYYZZZZ-B40E-41E7-830C-9F75484FAA4C" with
realm "net.unicon.tomcat7.realm.X509AuthenticationBypassingRealm"
27-Aug-2019 03:11:31.252 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.authenticate Authenticating client
certificate chain
27-Aug-2019 03:11:31.253 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.getPrincipal Got user name from X509
certificate: T=Apple Inc. Mac OS X (10.13), C=US, OU=MyDevices, O=Foo,
CN=user-foo/Enrollment-XXYYZZZZ-B40E-41E7-830C-9F75484FAA4C
27-Aug-2019 03:11:31.253 FINE [https-openssl-apr-8443-exec-1]
net.unicon.tomcat7.realm.X509AuthenticationBypassingRealm.getPrincipal
Returning GenericPrincipal with username T=Apple Inc. Mac OS X (10.13),
C=US, OU=MyDevices, O=Foo,
CN=user-foo/Enrollment-XXYYZZZZ-B40E-41E7-830C-9F75484FAA4C and role X509
27-Aug-2019 03:11:31.255 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.CombinedRealm.authenticate Authenticated user
"T=Apple Inc. Mac OS X (10.13), C=US, OU=MyDevices, O=Foo,
CN=user-foo/Enrollment-XXYYZZZZ-B40E-41E7-830C-9F75484FAA4C" with realm
"net.unicon.tomcat7.realm.X509AuthenticationBypassingRealm"
27-Aug-2019 03:11:31.255 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.register Authenticated
'T=Apple Inc. Mac OS X (10.13), C=US, OU=MyDevices, O=Foo,
CN=user-foo/Enrollment-XXYYZZZZ-B40E-41E7-830C-9F75484FAA4C' with type
'CLIENT_CERT'
27-Aug-2019 03:11:31.256 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.register Session ID
changed on authentication from [88DEB8C5AA0019057B9F65F600CC34DC.jvm1] to
[157941E37EF3E5DDF420BE31693D29B7.jvm1]
27-Aug-2019 03:11:31.256 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling
accessControl()
27-Aug-2019 03:11:31.256 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.hasResourcePermission Checking roles
GenericPrincipal[T=Apple Inc. Mac OS X (10.13), C=US, OU=MyDevices, O=Foo,
CN=user-foo/Enrollment-XXYYZZZZ-B40E-41E7-830C-9F75484FAA4C(X509,)]
27-Aug-2019 03:11:31.256 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.hasRole Username T=Apple Inc. Mac OS X
(10.13), C=US, OU=MyDevices, O=Foo,
CN=user-foo/Enrollment-XXYYZZZZ-B40E-41E7-830C-9F75484FAA4C has role X509
27-Aug-2019 03:11:31.256 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.realm.RealmBase.hasResourcePermission Role found: X509
27-Aug-2019 03:11:31.257 FINE [https-openssl-apr-8443-exec-1]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Successfully
passed all security constraints
27-Aug-2019 03:11:31.260 FINE [https-openssl-apr-8443-exec-1]
org.apache.coyote.AbstractProcessorLight.process Socket:
[org.apache.tomcat.util.net.AprEndpoint$AprSocketWrapper@7796385b:140007344664736],
Status in: [OPEN_READ], State out: [OPEN]
27-Aug-2019 03:11:31.260 FINE [https-openssl-apr-8443-exec-1]
org.apache.coyote.AbstractProtocol$ConnectionHandler.release Pushed
Processor [org.apache.coyote.http11.Http11Processor@3a59f8f8]
27-Aug-2019 03:11:31.305 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Processing
socket [140,007,344,664,736] with status [OPEN_READ]
27-Aug-2019 03:11:31.305 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Found
processor [null] for socket [140,007,344,664,736]
27-Aug-2019 03:11:31.305 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.AbstractProtocol$ConnectionHandler.process Popped
processor [org.apache.coyote.http11.Http11Processor@3a59f8f8] from cache
27-Aug-2019 03:11:31.306 FINE [https-openssl-apr-8443-exec-2]
org.apache.coyote.http11.Http11InputBuffer.parseRequestLine Received [GET
/idp/profile/SAML2/Redirect/SSO?execution=e1s1&_eventId_proceed=1 HTTP/1.1
Host: login-test.foo.com
Connection: keep-alive
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6)
AppleWebKit/537.36 (KHTML, like Gecko) Chrome/76.0.3809.100 Safari/537.36
Sec-Fetch-Mode: navigate
DNT: 1
Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3
Sec-Fetch-Site: none
Accept-Encoding: gzip, deflate, br
Accept-Language: en-US,en;q=0.9,zh-CN;q=0.8,zh;q=0.7,mt;q=0.6,zh-TW;q=0.5
Cookie: JSESSIONID=157941E37EF3E5DDF420BE31693D29B7.jvm1; x509passthrough=1
]
27-Aug-2019 03:11:31.306 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Security
checking request GET /idp/profile/SAML2/Redirect/SSO
27-Aug-2019 03:11:31.307 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.authenticator.AuthenticatorBase.invoke We have cached
auth type CLIENT_CERT for principal GenericPrincipal[T=Apple Inc. Mac OS X
(10.13), C=US, OU=MyDevices, O=Foo,
CN=user-foo/Enrollment-XXYYZZZZ-B40E-41E7-830C-9F75484FAA4C(X509,)]
27-Aug-2019 03:11:31.307 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking
constraint 'SecurityConstraint[X509AuthHandler]' against GET
/profile/SAML2/Redirect/SSO --> false
27-Aug-2019 03:11:31.307 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking
constraint 'SecurityConstraint[Automatic Forward to HTTPS/SSL]' against GET
/profile/SAML2/Redirect/SSO --> true
27-Aug-2019 03:11:31.307 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking
constraint 'SecurityConstraint[X509AuthHandler]' against GET
/profile/SAML2/Redirect/SSO --> false
27-Aug-2019 03:11:31.307 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.realm.RealmBase.findSecurityConstraints Checking
constraint 'SecurityConstraint[Automatic Forward to HTTPS/SSL]' against GET
/profile/SAML2/Redirect/SSO --> true
27-Aug-2019 03:11:31.307 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling
hasUserDataPermission()
27-Aug-2019 03:11:31.307 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.realm.RealmBase.hasUserDataPermission User data
constraint already satisfied
27-Aug-2019 03:11:31.308 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Calling
accessControl()
27-Aug-2019 03:11:31.308 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.realm.RealmBase.hasResourcePermission Checking roles
GenericPrincipal[T=Apple Inc. Mac OS X (10.13), C=US, OU=MyDevices, O=Foo,
CN=user-foo/Enrollment-XXYYZZZZ-B40E-41E7-830C-9F75484FAA4C(X509,)]
27-Aug-2019 03:11:31.308 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.realm.RealmBase.hasResourcePermission Passing all access
27-Aug-2019 03:11:31.308 FINE [https-openssl-apr-8443-exec-2]
org.apache.catalina.authenticator.AuthenticatorBase.invoke Successfully
passed all security constraints
ps:
* Unicon's x509 bypassing tomcat realm
https://github.com/Unicon/x509authentication-bypassing-tomcat-realm
* Additionally, also tried with allRolesMode="authOnly", with no obvious
difference.
