I'm looking for help in troubleshooting my NiFi 1.1.0 install. It's been
running stably for some time, but I restarted it this morning when I deployed
an updated custom NAR. Now it gets stuck at startup, see logs at the end.
There are no error messages, and the processes don't die. The process just
seems to be hanging waiting for something.
* My first thought was to try rolling back the modified nar, and even
just removing the nar all together since it was custom. Neither of these made
any difference.
* I also tried deleting the "work" folder, which has fixed nar
versioning issues for me in the past (not really related, but was worth a
shot). This made no difference.
* NiFi is set to start with java.arg.2=-Xms4G and java.arg.3=-Xmx8G,
22GB's of free RAM are available on the system (out of some 60GB's total).
* I've checked running processes, and when I stop NiFi no rouge
instances are left running.
* Since NiFi gets stuck right around the JettyServer step I checked to
see if any processes were using port 8443. No other processes are using this
port.
* I thought maybe a key file was being locked, but with NiFi off `lsof
| grep nifi` returns no locked files.
Nifi-app Log:
2017-01-26 20:23:43,359 INFO [main] org.eclipse.jetty.util.log Logging
initialized @90357ms
2017-01-26 20:23:43,418 INFO [main] org.apache.nifi.web.server.JettyServer
Configuring Jetty for HTTPs on port: 8443
2017-01-26 20:23:43,691 INFO [main] org.apache.nifi.web.server.JettyServer
Loading WAR:
/data/nifi/nifi-1.1.0/./work/nar/extensions/nifi-media-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-image-viewer-1.1.0.war
with context path set to /nifi-image-viewer-1.1.0
2017-01-26 20:23:43,702 INFO [main] org.apache.nifi.web.server.JettyServer
Loading WAR:
/data/nifi/nifi-1.1.0/./work/nar/extensions/nifi-update-attribute-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-update-attribute-ui-1.1.0.war
with context path set to /nifi-update-attribute-ui-1.1.0
2017-01-26 20:23:43,703 INFO [main] org.apache.nifi.web.server.JettyServer
Loading UI extension [ProcessorConfiguration, /nifi-update-attribute-ui-1.1.0]
for [org.apache.nifi.processors.attributes.UpdateAttribute]
2017-01-26 20:23:43,713 INFO [main] org.apache.nifi.web.server.JettyServer
Loading WAR:
/data/nifi/nifi-1.1.0/./work/nar/extensions/nifi-standard-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-standard-content-viewer-1.1.0.war
with context path set to /nifi-standard-content-viewer-1.1.0
2017-01-26 20:23:43,723 INFO [main] org.apache.nifi.web.server.JettyServer
Loading WAR:
/data/nifi/nifi-1.1.0/./work/nar/extensions/nifi-standard-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-jolt-transform-json-ui-1.1.0.war
with context path set to /nifi-jolt-transform-json-ui-1.1.0
2017-01-26 20:23:43,724 INFO [main] org.apache.nifi.web.server.JettyServer
Loading UI extension [ProcessorConfiguration,
/nifi-jolt-transform-json-ui-1.1.0] for
[org.apache.nifi.processors.standard.JoltTransformJSON]
2017-01-26 20:23:43,729 INFO [main] org.apache.nifi.web.server.JettyServer
Loading WAR:
/data/nifi/nifi-1.1.0/./work/nar/framework/nifi-framework-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-web-ui-1.1.0.war
with context path set to /nifi
2017-01-26 20:23:43,733 INFO [main] org.apache.nifi.web.server.JettyServer
Loading WAR:
/data/nifi/nifi-1.1.0/./work/nar/framework/nifi-framework-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-web-api-1.1.0.war
with context path set to /nifi-api
2017-01-26 20:23:43,735 INFO [main] org.apache.nifi.web.server.JettyServer
Loading WAR:
/data/nifi/nifi-1.1.0/./work/nar/framework/nifi-framework-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-web-content-viewer-1.1.0.war
with context path set to /nifi-content-viewer
2017-01-26 20:23:43,738 INFO [main] org.apache.nifi.web.server.JettyServer
Loading WAR:
/data/nifi/nifi-1.1.0/./work/nar/framework/nifi-framework-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-web-docs-1.1.0.war
with context path set to /nifi-docs
2017-01-26 20:23:43,753 INFO [main] org.apache.nifi.web.server.JettyServer
Loading documents web app with context path set to /nifi-docs
2017-01-26 20:23:43,761 INFO [main] org.apache.nifi.web.server.JettyServer
Loading WAR:
/data/nifi/nifi-1.1.0/./work/nar/framework/nifi-framework-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-web-error-1.1.0.war
with context path set to /
2017-01-26 20:23:43,804 INFO [main] org.eclipse.jetty.server.Server
jetty-9.3.9.v20160517
2017-01-26 20:23:44,748 INFO [main] o.e.jetty.server.handler.ContextHandler
Started
o.e.j.w.WebAppContext@4b511e61{/nifi-image-viewer-1.1.0,file:///data/nifi/nifi-1.1.0/work/jetty/nifi-image-viewer-1.1.0.war/webapp/,AVAILABLE}{./work/nar/extensions/nifi-media-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-image-viewer-1.1.0.war}
2017-01-26 20:23:46,566 INFO [main] o.e.jetty.server.handler.ContextHandler
Started
o.e.j.w.WebAppContext@26888c31{/nifi-update-attribute-ui-1.1.0,file:///data/nifi/nifi-1.1.0/work/jetty/nifi-update-attribute-ui-1.1.0.war/webapp/,AVAILABLE}{./work/nar/extensions/nifi-update-attribute-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-update-attribute-ui-1.1.0.war}
2017-01-26 20:23:47,365 INFO [main] o.e.jetty.server.handler.ContextHandler
Started
o.e.j.w.WebAppContext@7c840fe3{/nifi-standard-content-viewer-1.1.0,file:///data/nifi/nifi-1.1.0/work/jetty/nifi-standard-content-viewer-1.1.0.war/webapp/,AVAILABLE}{./work/nar/extensions/nifi-standard-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-standard-content-viewer-1.1.0.war}
2017-01-26 20:23:50,583 INFO [main] o.e.jetty.server.handler.ContextHandler
Started
o.e.j.w.WebAppContext@58b03029{/nifi-jolt-transform-json-ui-1.1.0,file:///data/nifi/nifi-1.1.0/work/jetty/nifi-jolt-transform-json-ui-1.1.0.war/webapp/,AVAILABLE}{./work/nar/extensions/nifi-standard-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-jolt-transform-json-ui-1.1.0.war}
2017-01-26 20:23:54,945 INFO [main] /nifi No Spring WebApplicationInitializer
types detected on classpath
2017-01-26 20:23:55,068 INFO [main] o.e.jetty.server.handler.ContextHandler
Started
o.e.j.w.WebAppContext@2358443e{/nifi,file:///data/nifi/nifi-1.1.0/work/jetty/nifi-web-ui-1.1.0.war/webapp/,AVAILABLE}{./work/nar/framework/nifi-framework-nar-1.1.0.nar-unpacked/META-INF/bundled-dependencies/nifi-web-ui-1.1.0.war}
2017-01-26 20:23:56,715 INFO [main] /nifi-api No Spring
WebApplicationInitializer types detected on classpath
2017-01-26 20:23:56,727 INFO [main] /nifi-api Initializing Spring root
WebApplicationContext
2017-01-26 20:24:04,029 INFO [main] o.a.nifi.properties.NiFiPropertiesLoader
Determined default nifi.properties path to be
'/data/nifi/nifi-1.1.0/./conf/nifi.properties'
2017-01-26 20:24:04,049 INFO [main] o.a.nifi.properties.NiFiPropertiesLoader
Determined default nifi.properties path to be
'/data/nifi/nifi-1.1.0/./conf/nifi.properties'
2017-01-26 20:24:04,064 INFO [main] o.a.nifi.properties.NiFiPropertiesLoader
Loaded 126 properties from /data/nifi/nifi-1.1.0/./conf/nifi.properties
2017-01-26 20:24:30,415 INFO [main] o.a.nifi.util.FileBasedVariableRegistry
Loaded 120 properties from system properties and environment variables
2017-01-26 20:24:30,415 INFO [main] o.a.nifi.util.FileBasedVariableRegistry
Loaded a total of 120 properties. Including precedence overrides effective
accessible registry key size is 120
NiFi-bootstrap Log (including when I killed it after about 10 minutes):
2017-01-26 20:22:12,986 INFO [main] org.apache.nifi.bootstrap.Command Starting
Apache NiFi...
2017-01-26 20:22:12,986 INFO [main] org.apache.nifi.bootstrap.Command Working
Directory: /data/nifi/nifi-1.1.0
2017-01-26 20:22:12,987 INFO [main] org.apache.nifi.bootstrap.Command Command:
java -classpath
/data/nifi/nifi-1.1.0/./conf:/data/nifi/nifi-1.1.0/./lib/logback-classic-1.1.3.jar:/data/nifi/nifi-1.1.0/./lib/logback-core-1.1.3.jar:/data/nifi/nifi-1.1.0/./lib/slf4j-api-1.7.12.jar:/data/nifi/nifi-1.1.0/./lib/jcl-over-slf4j-1.7.12.jar:/data/nifi/nifi-1.1.0/./lib/jul-to-slf4j-1.7.12.jar:/data/nifi/nifi-1.1.0/./lib/log4j-over-slf4j-1.7.12.jar:/data/nifi/nifi-1.1.0/./lib/nifi-api-1.1.0.jar:/data/nifi/nifi-1.1.0/./lib/nifi-framework-api-1.1.0.jar:/data/nifi/nifi-1.1.0/./lib/nifi-runtime-1.1.0.jar:/data/nifi/nifi-1.1.0/./lib/nifi-nar-utils-1.1.0.jar:/data/nifi/nifi-1.1.0/./lib/nifi-properties-1.1.0.jar:/data/nifi/nifi-1.1.0/./lib/nifi-documentation-1.1.0.jar:/data/nifi/nifi-1.1.0/./lib/bcprov-jdk15on-1.54.jar:/data/nifi/nifi-1.1.0/./lib/commons-lang3-3.4.jar:/data/nifi/nifi-1.1.0/./lib/ngdbc.jar:/data/nifi/nifi-1.1.0/./lib/ojdbc6.jar:/data/nifi/nifi-1.1.0/./lib/sqljdbc42.jar:/data/nifi/nifi-1.1.0/./lib/tdgssconfig-15.10.00.09.jar:/data/nifi/nifi-1.1.0/./lib/terajdbc4-15.10.00.09.jar
-Dorg.apache.jasper.compiler.disablejsr199=true -Xmx8G -Xms4G
-agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=10000
-Dsun.net.http.allowRestrictedHeaders=true -Djava.net.preferIPv4Stack=true
-Djava.awt.headless=true -XX:+UseG1GC
-Djava.protocol.handler.pkgs=sun.net.www.protocol
-Dnifi.properties.file.path=/data/nifi/nifi-1.1.0/./conf/nifi.properties
-Dnifi.bootstrap.listen.port=57107 -Dapp=NiFi
-Dorg.apache.nifi.bootstrap.config.log.dir=/data/nifi/nifi-logs
org.apache.nifi.NiFi
2017-01-26 20:22:13,140 INFO [NiFi logging handler] org.apache.nifi.StdOut
Listening for transport dt_socket at address: 10000
2017-01-26 20:22:14,340 INFO [NiFi Bootstrap Command Listener]
org.apache.nifi.bootstrap.RunNiFi Apache NiFi now running and listening for
Bootstrap requests on port 38045
2017-01-26 20:38:22,626 INFO [main] o.a.n.b.NotificationServiceManager
Successfully loaded the following 0 services: []
2017-01-26 20:38:22,633 INFO [main] org.apache.nifi.bootstrap.RunNiFi
Registered no Notification Services for Notification Type NIFI_STARTED
2017-01-26 20:38:22,633 INFO [main] org.apache.nifi.bootstrap.RunNiFi
Registered no Notification Services for Notification Type NIFI_STOPPED
2017-01-26 20:38:22,633 INFO [main] org.apache.nifi.bootstrap.RunNiFi
Registered no Notification Services for Notification Type NIFI_DIED
2017-01-26 20:38:32,663 ERROR [main] org.apache.nifi.bootstrap.Command Failed
to send shutdown command to port 38045 due to java.net.SocketTimeoutException:
Read timed out. Will kill the NiFi Process with PID 19744.
2017-01-26 20:38:33,197 INFO [main] org.apache.nifi.bootstrap.RunNiFi Status
File no longer exists. Will not restart NiFi
