I am working with Tomcat 9.0.16 on Debian 9.6. Running my app on port 8080 works no problem. So I am confident that my app is not the problem.
I am trying to configure Tomcat to use port 443. I have a cert (not self signed) and believe that I have it in the correct format... PKCS12
This is my connector from server.xml:
<Connector port="443"
protocol="org.apache.coyote.http11.Http11AprProtocol"
maxThreads="150"
scheme="https"
secure="true"
SSLEnabled="true" >
<UpgradeProtocol className="org.apache.coyote.http2.Http2Protocol" />
<SSLHostConfig hostname="radar.bellhowell.net"
protocols="TLSv1.3,TLSv1.2,TLSv1.1,TLSv1">
<Certificate
certificateFile="/radar-certs/radar_certificate.p12"
certificateChainFile="/radar-certs/radar_chain.p12"
certificateKeyFile="/radar-certs/radar_bellhowell_net_key.pem"
certificateKeyPassword="YPbATR1iN28!8qT3"
type="RSA" />
</SSLHostConfig>
</Connector>
I also have these connectors in the same file, which may or may not be necessary.
<Connector port="8080" protocol="HTTP/1.1"
connectionTimeout="20000"
redirectPort="443" />
<Connector port="80" protocol="HTTP/1.1"
connectionTimeout="20000"
redirectPort="443" />
This is one startup cycle from catalina.out:
<6>Pausing ProtocolHandler ["http-apr-8080"]
<6>Pausing ProtocolHandler ["http-apr-80"]
<6>Pausing ProtocolHandler ["https-openssl-apr-443"]
<6>Stopping service [Catalina]
<6>Closing WebApplicationContext for namespace 'radar-servlet': startup date [Tue May 28 10:05:36 EDT 2019]; parent: Root WebApplicationContext
<6>Closing Root WebApplicationContext: startup date [Tue May 28 10:05:26 EDT 2019]; root of context hierarchy
<6>Shutting down ExecutorService 'myScheduler'
<6>Closing JPA EntityManagerFactory for persistence unit 'default'
<4>The web application [radar] registered the JDBC driver [org.postgresql.Driver] but failed to unregister it when the web application was stopped. To prevent a memory <4>The web application [radar] appears to have started a thread named [Tomcat JDBC Pool Cleaner[22756955:1559052328829]] but has failed to stop it. This is very likely java.lang.Object.wait(Native Method)
java.util.TimerThread.mainLoop(Timer.java:552)
java.util.TimerThread.run(Timer.java:505)
<6>Stopping ProtocolHandler ["http-apr-8080"]
<6>Destroying ProtocolHandler ["http-apr-8080"]
<6>Stopping ProtocolHandler ["http-apr-80"]
<6>Destroying ProtocolHandler ["http-apr-80"]
<6>Stopping ProtocolHandler ["https-openssl-apr-443"]
<6>Destroying ProtocolHandler ["https-openssl-apr-443"]
<4>Problem with JAR file [/usr/share/tomcat9/lib/catalina-jmx-remote.jar], exists: [false], canRead: [false]
<4>Match [Server/Service/Connector/SSLHostConfig] failed to set property [hostname] to [radar.bellhowell.net]
<4>The protocol [TLSv1.2] was added to the list of protocols on the SSLHostConfig named [_default_]. Check if a +/- prefix is missing.
<4>The protocol [TLSv1.1] was added to the list of protocols on the SSLHostConfig named [_default_]. Check if a +/- prefix is missing.
<4>The protocol [TLSv1] was added to the list of protocols on the SSLHostConfig named [_default_]. Check if a +/- prefix is missing.
<6>Server version name: Apache Tomcat/9.0.16 (Debian)
<6>Server built: Feb 26 2019 08:17:32 UTC
<6>Server version number: 9.0.16.0
<6>OS Name: Linux
<6>OS Version: 4.9.0-8-amd64
<6>Architecture: amd64
<6>Java Home: /usr/lib/jvm/java-8-openjdk-amd64/jre
<6>JVM Version: 1.8.0_212-8u212-b01-1~deb9u1-b01
<6>JVM Vendor: Oracle Corporation
<6>CATALINA_BASE: /usr/share/tomcat9-root
<6>CATALINA_HOME: /usr/share/tomcat9
<6>Command line argument: -Djava.util.logging.config.file=/usr/share/tomcat9-root/conf/logging.properties
<6>Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
<6>Command line argument: -Djava.net.preferIPv4Stack=true
<6>Command line argument: -Djava.net.preferIPv4Addressess=true
<6>Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
<6>Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
<6>Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
<6>Command line argument: -Dignore.endorsed.dirs=
<6>Command line argument: -Dcatalina.base=/usr/share/tomcat9-root
<6>Command line argument: -Dcatalina.home=/usr/share/tomcat9
<6>Command line argument: -Djava.io.tmpdir=/usr/share/tomcat9-root/temp
<6>Loaded APR based Apache Tomcat Native library [1.2.21] using APR version [1.7.0].
<6>APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true].
<6>APR/OpenSSL configuration: useAprConnector [true], useOpenSSL [true]
<6>OpenSSL successfully initialized [OpenSSL 1.1.0j 20 Nov 2018]
<6>Initializing ProtocolHandler ["http-apr-8080"]
<6>Initializing ProtocolHandler ["http-apr-80"]
<2>Failed to initialize component [Connector[HTTP/1.1-80]]
<2>org.apache.catalina.LifecycleException: Protocol handler initialization failed
<2> at org.apache.catalina.connector.Connector.initInternal(Connector.java:983)
<2> at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
<2> at org.apache.catalina.core.StandardService.initInternal(StandardService.java:535)
<2> at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
<2> at org.apache.catalina.core.StandardServer.initInternal(StandardServer.java:1055)
<2> at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
<2> at org.apache.catalina.startup.Catalina.load(Catalina.java:589)
<2> at org.apache.catalina.startup.Catalina.load(Catalina.java:612)
<2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
<2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
<2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
<2> at java.lang.reflect.Method.invoke(Method.java:498)
<2> at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:306)
<2> at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:491)
<2>Caused by: java.lang.Exception: Socket bind failed: [13] [Permission denied]
<2> at org.apache.tomcat.util.net.AprEndpoint.bind(AprEndpoint.java:336)
<2> at org.apache.tomcat.util.net.AbstractEndpoint.bindWithCleanup(AbstractEndpoint.java:1085)
<2> at org.apache.tomcat.util.net.AbstractEndpoint.init(AbstractEndpoint.java:1098)
<2> at org.apache.coyote.AbstractProtocol.init(AbstractProtocol.java:557)
<2> at org.apache.coyote.http11.AbstractHttp11Protocol.init(AbstractHttp11Protocol.java:74)
<2> at org.apache.catalina.connector.Connector.initInternal(Connector.java:980)
<2> ... 13 more
<2>
<6>The ["https-openssl-apr-443"] connector has been configured to support negotiation to [h2] via ALPN
<6>Initializing ProtocolHandler ["https-openssl-apr-443"]
<2>Failed to initialize component [Connector[HTTP/1.1-443]]
<2>org.apache.catalina.LifecycleException: Protocol handler initialization failed
<2> at org.apache.catalina.connector.Connector.initInternal(Connector.java:983)
<2> at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
<2> at org.apache.catalina.core.StandardService.initInternal(StandardService.java:535)
<2> at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
<2> at org.apache.catalina.core.StandardServer.initInternal(StandardServer.java:1055)
<2> at org.apache.catalina.util.LifecycleBase.init(LifecycleBase.java:136)
<2> at org.apache.catalina.startup.Catalina.load(Catalina.java:589)
<2> at org.apache.catalina.startup.Catalina.load(Catalina.java:612)
<2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
<2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
<2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
<2> at java.lang.reflect.Method.invoke(Method.java:498)
<2> at org.apache.catalina.startup.Bootstrap.load(Bootstrap.java:306)
<2> at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:491)
<2>Caused by: java.lang.Exception: Socket bind failed: [13] [Permission denied]
<2> at org.apache.tomcat.util.net.AprEndpoint.bind(AprEndpoint.java:336)
<2> at org.apache.tomcat.util.net.AbstractEndpoint.bindWithCleanup(AbstractEndpoint.java:1085)
<2> at org.apache.tomcat.util.net.AbstractEndpoint.init(AbstractEndpoint.java:1098)
<2> at org.apache.coyote.AbstractProtocol.init(AbstractProtocol.java:557)
<2> at org.apache.coyote.http11.AbstractHttp11Protocol.init(AbstractHttp11Protocol.java:74)
<2> at org.apache.catalina.connector.Connector.initInternal(Connector.java:980)
<2> ... 13 more
<2>
<6>Server initialization in [761] milliseconds
<6>Starting service [Catalina]
<6>Starting Servlet engine: [Apache Tomcat/9.0.16 (Debian)]
<2>Unable to create directory for deployment: [/usr/share/tomcat9/etc/Catalina/localhost]
<6>Deploying web application archive [/usr/share/tomcat9-root/webapps/radar.war]
<6>At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were fountime and JSP compilation time.
<6>Root WebApplicationContext: initialization started
<6>Refreshing Root WebApplicationContext: startup date [Tue May 28 10:23:59 EDT 2019]; root of context hierarchy
<6>Loading XML bean definitions from ServletContext resource [/WEB-INF/classes/main/resources/security-config.xml]
<6>You are running with Spring Security Core 5.0.3.RELEASE
<6>Spring Security 'config' module version is 5.0.3.RELEASE
<6>Expressions were enabled for method security but no SecurityExpressionHandler was configured. All hasPermision() expressions will evaluate to false.
<6>Checking sorted filter chain: [Root bean: class [org.springframework.security.web.context.SecurityContextPersistenceFilter]; scope=; abstract=false; lazyInit=false; se; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null, order = 200, Root bean: class [org.springframework.security.web.context.r; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMeot bean: class [org.springframework.security.web.header.HeaderWriterFilter]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidatnitMethodName=null; destroyMethodName=null, order = 500, Root bean: class [null]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCanty.config.http.HttpConfigurationBuilder$SecurityContextHolderAwareRequestFilterBeanFactory#0; factoryMethodName=getBean; initMethodName=null; destroyMethodName=null, orication.AnonymousAuthenticationFilter]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanNam=null, order = 2100, Root bean: class [org.springframework.security.web.access.ExceptionTranslationFilter]; scope=; abstract=false; lazyInit=false; autowireMode=0; depenull; factoryMethodName=null; initMethodName=null; destroyMethodName=null, order = 2300, <org.springframework.security.web.access.intercept.FilterSecurityInterceptor#0><6>Loading XML bean definitions from ServletContext resource [/WEB-INF/classes/main/resources/applicationContext.xml]
<6>Building JPA container EntityManagerFactory for persistence unit 'default'
<6>Initialized JPA EntityManagerFactory for persistence unit 'default'
<6>Creating filter chain: Ant [pattern='/rest/user/authenticate'], []
<6>Creating filter chain: Ant [pattern='/rest/user/reset'], []
[DEBUG] 2019-05-28 10:24:08.359 [main] JwtAuthenticationFilter - constructor called
<6>Creating filter chain: Ant [pattern='/rest/**'], [org.springframework.security.web.context.SecurityContextPersistenceFilter@3b8bb9a0, org.springframework.security.we.bh.radar.jwt.JwtAuthenticationFilter@2c80d2e0, org.springframework.security.web.header.HeaderWriterFilter@232cc375, org.springframework.security.web.servletapi.Security.web.authentication.AnonymousAuthenticationFilter@3b71b6b1, org.springframework.security.web.access.ExceptionTranslationFilter@4a3cc680, org.springframework.security.w<6>Initializing ExecutorService 'myScheduler'
[DEBUG] 2019-05-28 10:24:08.974 [main] JwtSecretProvider - These are the secrets:
[DEBUG] 2019-05-28 10:24:08.975 [main] JwtSecretProvider - HS256 FWbd7/awCYZnUZpz3+2t1hWz8cYjehxe/3DuAUEmkfM=
[DEBUG] 2019-05-28 10:24:08.975 [main] JwtSecretProvider - HS512 yru+6pv5trSFzVJPK+HZ3qUYCdNlJt4BWFGrjqhSGU3poR48pq3yQsmf6aMyaa3iOGGlDcsHmcjEgVCBcdboyQ==
[DEBUG] 2019-05-28 10:24:08.976 [main] JwtSecretProvider - HS384 vQF20hkaZ9HaoW0URF8jldQ7jE1DGDEuYrSP7Km9qiNsEUqrnHbYKnx3MbAXie0I
[DEBUG] 2019-05-28 10:24:09.494 [main] DaoBase - constructor (), this = com.bh.radar.dao.DaoEngagement@1da0ad22
[DEBUG] 2019-05-28 10:24:09.544 [main] DaoBase - constructor (), this = com.bh.radar.dao.DaoDeliverableTask@67534bfc
[DEBUG] 2019-05-28 10:24:09.566 [main] DaoBase - constructor (), this = com.bh.radar.dao.DaoDeliverablePhoto@561797fd
[DEBUG] 2019-05-28 10:24:09.582 [main] DaoBase - constructor (), this = com.bh.radar.dao.DaoIncident@289e504f
[DEBUG] 2019-05-28 10:24:09.599 [main] DaoBase - constructor (), this = com.bh.radar.dao.DaoIncidentPhoto@59c08dd4
[DEBUG] 2019-05-28 10:24:09.615 [main] DaoBase - constructor (), this = com.bh.radar.dao.DaoUser@6777bc90
[DEBUG] 2019-05-28 10:24:09.636 [main] DaoBase - constructor (), this = com.bh.radar.dao.DaoEmailAddress@7de9d7c7
[DEBUG] 2019-05-28 10:24:09.724 [myScheduler-1] UtilComplianceTask - compliance task fired
<6>Root WebApplicationContext: initialization completed in 9832 ms
<6>FrameworkServlet 'radar': initialization started
<6>Refreshing WebApplicationContext for namespace 'radar-servlet': startup date [Tue May 28 10:24:09 EDT 2019]; parent: Root WebApplicationContext
<6>Loading XML bean definitions from ServletContext resource [/WEB-INF/radar-servlet.xml]
<6>Mapped "{[/rest/deliverable/photo/add/{id}/{photoKey}],methods=[POST],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.Str.web.multipart.MultipartFile,int,short)
<6>Mapped "{[/rest/deliverable/photo/markNA/{id}/{photoKey}],methods=[POST],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.<6>Mapped "{[/rest/deliverable/photo/delete/{id}],methods=[DELETE],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> c<6>Mapped "{[/rest/deliverable/task/delete/{id}],methods=[DELETE],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> co<6>Mapped "{[/rest/engagement/retrieve],methods=[GET],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.bh.radar.e<6>Mapped "{[/rest/engagement/retrieve/{inStoreNum}],methods=[GET],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> cing)
<6>Mapped "{[/rest/engagement/stores/retrieve],methods=[GET],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.bh.<6>Mapped "{[/rest/engagement/create],methods=[POST],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.bh.radar.enper,java.lang.String)
<6>Mapped "{[/rest/engagement/update/{engagementId}],methods=[PUT],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.bh.radar.bo.BoEngagementWrapper)
<6>Mapped "{[/rest/engagement/{id}/addReport],methods=[POST],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.bh.b.multipart.MultipartFile,int)
<6>Mapped "{[/rest/engagement/emailDaily/{engagementId}],methods=[GET],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.Strin<6>Mapped "{[/rest/engagement/emailFinal/{engagementId}],methods=[GET],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.Strin<6>Mapped "{[/rest/engagement/uniqueStores],methods=[GET],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.bh.rad<6>Mapped "{[/rest/engagement/uniqueCityStates],methods=[GET],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.bh<6>Mapped "{[/rest/incident/photo/add/{incidentFk}],methods=[POST],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> cipart.MultipartFile,int)
<6>Mapped "{[/rest/incident/photo/delete/{id}],methods=[DELETE],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.<6>Mapped "{[/rest/reports/byStore],methods=[GET],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.bh.radar.endpog.String)
<6>Mapped "{[/rest/reports/byCity],methods=[GET],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.String> com.bh.radar.endpoiString,java.lang.String)
<6>Mapped "{[/rest/user/authenticate],methods=[POST],consumes=[application/json],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.ar.bo.BoUser)
<6>Mapped "{[/rest/user/reset],methods=[POST],consumes=[application/json],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.lang.Ster)
<6>Mapped "{[/rest/user/register],methods=[POST],consumes=[application/json],produces=[application/json]}" onto public org.springframework.http.ResponseEntity<java.langUser)
<6>Looking for @ControllerAdvice: WebApplicationContext for namespace 'radar-servlet': startup date [Tue May 28 10:24:09 EDT 2019]; parent: Root WebApplicationContext
<6>Looking for @ControllerAdvice: WebApplicationContext for namespace 'radar-servlet': startup date [Tue May 28 10:24:09 EDT 2019]; parent: Root WebApplicationContext
<6>FrameworkServlet 'radar': initialization completed in 1417 ms
<6>Deployment of web application archive [/usr/share/tomcat9-root/webapps/radar.war] has finished in [16,289] ms
<6>Deploying web application directory [/usr/share/tomcat9-root/webapps/radarui]
<6>At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were fountime and JSP compilation time.
<6>Deployment of web application directory [/usr/share/tomcat9-root/webapps/radarui] has finished in [1,419] ms
<6>Starting ProtocolHandler ["http-apr-8080"]
<6>Server startup in [17,790] milliseconds
I have found several posts here on on various blogs the mention configuring Java to prefer IPv4, so, here is my setenv.sh script:
# setup the environment for running tomcat
#update the LD_LIBRARY_PATH with the path to updated apr and libcatnative libraries
# export LD_LIBRARY_PATH="$LD_LIBRARY_PATH:/usr/share/apr/lib"
export LD_LIBRARY_PATH='$LD_LIBRARY_PATH:/usr/local/apr/lib'
# force tomcat to use IPv4
export JAVA_OPTS="$JAVA_OPTS -Djava.net.preferIPv4Stack=true -Djava.net.preferIPv4Addressess=true"
# set locations for tomcat components
export CATALINA_HOME="/usr/share/tomcat9"
export CATALINA_BASE="/usr/share/tomcat9-root"
export CATALINA_TMPDIR="/usr/share/tomcat9-root/temp"
# set the location of the catalina PID file for `catalina.sh`
# the user who will start tomcat must have write permissions for $CATALINA_BASE
export CATALINA_PID="$CATALINA_BASE/tomcat.pid"
I did notice as I was writing this question that despite my JAVA_OPTS in setenv.sh, it looks to me like Tomcat, or more specifically APR, is still using IPv6. Do I need to rebuild APR with the same JAVA_OPTS as I have in the setenv.sh?
The real question, I guess is what am I doing wrong? And, what more information do you need from me?
Update
If I call catalina.sh start as root, I do not get the errors above... I did chown root:tomcat /etc/authbind/byport/443 and chown root:tomcat /etc/authbind/byport/80 and tried again as a non-root user who is a member of the tomcat group and still get the errors.
The point of my question is that I am specifically trying to get things setup so that I can start tomcat as a non-root user. Since I am not putting tomcat behind another server I feel that starting as a non-root user is an important security step.
