Unable to Restart Lucee from Gradle SSH Task


#1

I have a Gradle based deployment process for pushing code changes to the server.

After I push changes to the server, I want to restart Lucee.

I am using an SSH gradle task to run the commands. This task shuts down Lucee with no problem, and, based on what I see in the console when I run the Gradle task, Lucee starts without errors…however, Lucee never actually starts.

This is what I am trying to run:

println '****************** Restarting Lucee ******************'
executeSudo '/opt/lucee/lucee_ctl restart'

Here is the output I see in the console:

****************** Restarting Lucee ******************
webServer#12| * Shutting down Lucee: . . . . . . . Tomcat stopped.
webServer#12|. [DONE]
webServer#12| * Starting Lucee: Using CATALINA_BASE:   /opt/lucee/tomcat
webServer#12|Using CATALINA_HOME:   /opt/lucee/tomcat
webServer#12|Using CATALINA_TMPDIR: /opt/lucee/tomcat/temp
webServer#12|Using JRE_HOME:        /opt/jdk/jre
webServer#12|Using CLASSPATH:       /opt/lucee/tomcat/bin/bootstrap.jar:/opt/lucee/tomcat/bin/tomcat-juli.jar
webServer#12|Using CATALINA_PID:    /opt/lucee/tomcat/work/tomcat.pid
webServer#12|Tomcat started.
webServer#12|. . . [DONE]
webServer#12|--------------------------------------------------------
webServer#12|It may take a few moments for Lucee to start processing
webServer#12|CFML templates. This is normal.
webServer#12|--------------------------------------------------------

When I look in catalina.out, I do see some differences between start up with the Gradle task and simply running /opt/lucee/lucee_ctl restart from a command line while SSH’d into the server.

Here is what I have seen in catalina.out

When starting in the Gradle task:

24-Mar-2018 11:38:42.470 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.28
24-Mar-2018 11:38:42.525 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Feb 6 2018 23:10:25 UTC
24-Mar-2018 11:38:42.525 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.28.0
24-Mar-2018 11:38:42.526 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
24-Mar-2018 11:38:42.526 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            2.6.32-696.20.1.el6.x86_64
24-Mar-2018 11:38:42.526 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
24-Mar-2018 11:38:42.526 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /path/to/lucee/jdk/jre/jre
24-Mar-2018 11:38:42.526 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_152-b16
24-Mar-2018 11:38:42.526 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
24-Mar-2018 11:38:42.527 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /path/to/lucee/tomcat
24-Mar-2018 11:38:42.527 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /path/to/lucee/tomcat
24-Mar-2018 11:38:42.527 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/path/to/lucee/tomcat/conf/logging.properties
24-Mar-2018 11:38:42.528 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
24-Mar-2018 11:38:42.528 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
24-Mar-2018 11:38:42.528 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
24-Mar-2018 11:38:42.528 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms256m
24-Mar-2018 11:38:42.528 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx512m
24-Mar-2018 11:38:42.528 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
24-Mar-2018 11:38:42.529 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/path/to/lucee/tomcat
24-Mar-2018 11:38:42.529 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/path/to/lucee/tomcat
24-Mar-2018 11:38:42.529 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/path/to/lucee/tomcat/temp
24-Mar-2018 11:38:42.529 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib]
24-Mar-2018 11:38:42.949 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8888"]
24-Mar-2018 11:38:42.971 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
24-Mar-2018 11:38:43.008 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
24-Mar-2018 11:38:43.011 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
24-Mar-2018 11:38:43.012 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 1632 ms
24-Mar-2018 11:38:43.045 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
24-Mar-2018 11:38:43.045 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.28
[mod_cfml] Starting mod_cfml version: 1.1.05
24-Mar-2018 11:38:43.097 INFO [127.0.0.1-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/path/to/lucee/tomcat/webapps/ROOT]

When starting while SSH’d into a console:

24-Mar-2018 11:40:17.166 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server version:        Apache Tomcat/8.5.28
24-Mar-2018 11:40:17.171 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server built:          Feb 6 2018 23:10:25 UTC
24-Mar-2018 11:40:17.171 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Server number:         8.5.28.0
24-Mar-2018 11:40:17.171 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Name:               Linux
24-Mar-2018 11:40:17.171 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log OS Version:            2.6.32-696.20.1.el6.x86_64
24-Mar-2018 11:40:17.171 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Architecture:          amd64
24-Mar-2018 11:40:17.171 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Java Home:             /path/to/lucee/jdk/jre/jre
24-Mar-2018 11:40:17.172 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Version:           1.8.0_152-b16
24-Mar-2018 11:40:17.172 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log JVM Vendor:            Oracle Corporation
24-Mar-2018 11:40:17.172 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_BASE:         /path/to/lucee/tomcat
24-Mar-2018 11:40:17.172 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log CATALINA_HOME:         /path/to/lucee/tomcat
24-Mar-2018 11:40:17.173 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.config.file=/path/to/lucee/tomcat/conf/logging.properties
24-Mar-2018 11:40:17.173 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
24-Mar-2018 11:40:17.173 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
24-Mar-2018 11:40:17.173 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
24-Mar-2018 11:40:17.173 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xms256m
24-Mar-2018 11:40:17.174 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Xmx512m
24-Mar-2018 11:40:17.174 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dignore.endorsed.dirs=
24-Mar-2018 11:40:17.174 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.base=/path/to/lucee/tomcat
24-Mar-2018 11:40:17.174 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Dcatalina.home=/path/to/lucee/tomcat
24-Mar-2018 11:40:17.174 INFO [main] org.apache.catalina.startup.VersionLoggerListener.log Command line argument: -Djava.io.tmpdir=/path/to/lucee/tomcat/temp
24-Mar-2018 11:40:17.174 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib]
24-Mar-2018 11:40:17.543 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8888"]
24-Mar-2018 11:40:17.566 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
24-Mar-2018 11:40:17.580 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-8009"]
24-Mar-2018 11:40:17.583 INFO [main] org.apache.tomcat.util.net.NioSelectorPool.getSharedSelector Using a shared selector for servlet write/read
24-Mar-2018 11:40:17.584 INFO [main] org.apache.catalina.startup.Catalina.load Initialization processed in 1353 ms
24-Mar-2018 11:40:17.628 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
24-Mar-2018 11:40:17.628 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet Engine: Apache Tomcat/8.5.28
[mod_cfml] Starting mod_cfml version: 1.1.05
24-Mar-2018 11:40:17.680 INFO [127.0.0.1-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/path/to/lucee/tomcat/webapps/ROOT]
24-Mar-2018 11:40:18.768 INFO [127.0.0.1-startStop-1] org.apache.jasper.servlet.TldScanner.scanJars 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 found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
24-Mar-2018 11:40:21.404 WARNING [127.0.0.1-startStop-1] org.apache.catalina.util.SessionIdGeneratorBase.createSecureRandom Creation of SecureRandom instance for session ID generation using [SHA1PRNG] took [2,525] milliseconds.
root-directory:/path/to/lucee/tomcat
classic-root-directory:/path/to/lucee/lib
===================================================================
SERVER CONTEXT
-------------------------------------------------------------------
- config:/path/to/lucee/tomcat/lucee-server/context
- loader-version:6.0
- core-version:5.2.6.59
===================================================================

2018-03-24 11:40:24.784 start reading config
2018-03-24 11:40:24.827 fixed LFI
2018-03-24 11:40:24.827 fixed salt
2018-03-24 11:40:24.830 fixed S3
2018-03-24 11:40:24.830 fixed PSQ
2018-03-24 11:40:24.830 fixed logging
2018-03-24 11:40:24.832 fixed Extension
2018-03-24 11:40:24.833 fixed component mappings
2018-03-24 11:40:24.833 fixed to big felix.log
2018-03-24 11:40:24.833 deploy web context
2018-03-24 11:40:24.881 loaded config
2018-03-24 11:40:24.884 loaded constants
2018-03-24 11:40:24.903 loaded loggers
2018-03-24 11:40:24.904 loaded temp dir
2018-03-24 11:40:24.908 loaded id
2018-03-24 11:40:24.908 loaded version
2018-03-24 11:40:24.910 loaded security
2018-03-24 11:40:24.912 loaded lib
2018-03-24 11:40:26.127 Start CFML Controller
2018-03-24 11:40:26.145 touched monitors
===================================================================
WEB CONTEXT (e07d7ff0a4784204420747912bb703a4)
-------------------------------------------------------------------
- config:/path/to/lucee/tomcat/webapps/ROOT/WEB-INF/lucee
- webroot:/path/to/lucee/tomcat/webapps/ROOT/
- hash:e07d7ff0a4784204420747912bb703a4
- label:e07d7ff0a4784204420747912bb703a4
===================================================================

2018-03-24 11:40:26.260 fixed LFI
2018-03-24 11:40:26.261 fixed salt
2018-03-24 11:40:26.262 fixed S3
2018-03-24 11:40:26.262 fixed PSQ
2018-03-24 11:40:26.262 fixed logging
2018-03-24 11:40:26.262 fixed Extension
2018-03-24 11:40:26.262 fixed component mappings
2018-03-24 11:40:26.262 fixed to big felix.log
2018-03-24 11:40:26.263 deploy web context
2018-03-24 11:40:26.263 loaded config
2018-03-24 11:40:26.267 loaded constants
2018-03-24 11:40:26.274 loaded loggers
2018-03-24 11:40:26.275 loaded temp dir
2018-03-24 11:40:26.276 loaded id
2018-03-24 11:40:26.276 loaded version
2018-03-24 11:40:26.277 loaded security
2018-03-24 11:40:26.277 loaded lib
24-Mar-2018 11:40:26.486 INFO [127.0.0.1-startStop-1] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/path/to/lucee/tomcat/webapps/ROOT] has finished in [8,807] ms
24-Mar-2018 11:40:26.533 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8888"]
24-Mar-2018 11:40:26.558 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-8009"]
24-Mar-2018 11:40:26.563 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in 8978 ms

Here is what I see in the console when I start the Lucee from console after the Gradle task failed.

* Starting Lucee: Using CATALINA_BASE:   /opt/lucee/tomcat
Using CATALINA_HOME:   /opt/lucee/tomcat
Using CATALINA_TMPDIR: /opt/lucee/tomcat/temp
Using JRE_HOME:        /opt/lucee/jdk/jre
Using CLASSPATH:       /opt/lucee/tomcat/bin/bootstrap.jar:/opt/lucee/tomcat/bin/tomcat-juli.jar
Using CATALINA_PID:    /opt/lucee/tomcat/work/tomcat.pid
Existing PID file found during start.
Removing/clearing stale PID file.
Tomcat started.
. . . [DONE]
--------------------------------------------------------
It may take a few moments for Lucee to start processing
CFML templates. This is normal.
--------------------------------------------------------

Can anyone shed some light on why the command doesn’t execute the same when called via an SSH task in Gradle?


#2

I figured it out.

The Gradle SSH task was connecting to the server using PTY, as opposed to a regular terminal (TTY) when I ran the command manually. This was causing issues with Tomcat starting up because the connection would end before the startup process was completed.

Long story short: adding ‘nohup’ to the command got it working as expected.

executeSudo 'nohup /opt/lucee/lucee_ctl start'