Problem with logging

[Valentin Polezhaev]

Hello,

On transformation screen we have 'An unexpected error occurred An error occurred while executing the transformation'. According to browser console it appears when proxy/v1/spark/shell/transform requested, error is 'Failed to load resource: the server responded with a status of 500 (Internal Server Error)' without any details.

Trying to investigate problem, we have stucked with logging problems. Logs contain nothing about problem, but there are problems with logging itself.

In kylo-spark-shell.err we get:

15:22:48,381 SpringApplication.handleRunFailure: Application startup failed

org.springframework.context.ApplicationContextException: Unable to start embedded container; nested exception is org.springframework.boot.context.embedded.EmbeddedServletContainerException: Unable to start embedded Tomcat

...

Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'org.springframework.boot.autoconfigure.jersey.JerseyAutoConfiguration': Injection of autowired dependencies failed; nested exception is org.springframework.beans.factory.BeanCreationException: Could not autowire field: private org.glassfish.jersey.server.ResourceConfig org.springframework.boot.autoconfigure.jersey.JerseyAutoConfiguration.config; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'jerseyConfig' defined in com.thinkbiganalytics.spark.SparkShellApp: Unsatisfied dependency expressed through constructor argument with index 0 of type [com.thinkbiganalytics.spark.service.TransformService]: Error creating bean with name 'transformService' defined in com.thinkbiganalytics.spark.SparkShellApp: Unsatisfied dependency expressed through constructor argument with index 1 of type [com.thinkbiganalytics.spark.repl.SparkScriptEngine]: Error creating bean with name 'sparkScriptEngine' defined in URL [jar:file:/opt/kylo/kylo-services/lib/app/kylo-spark-shell-client-v2-0.8.2.1-SNAPSHOT.jar!/com/thinkbiganalytics/spark/repl/SparkScriptEngine.class]: Instantiation of bean failed; nested exception is java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of org/apache/spark/util/ChildFirstURLClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for the method's defining class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type org/slf4j/ILoggerFactory used in the signature; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sparkScriptEngine' defined in URL [jar:file:/opt/kylo/kylo-services/lib/app/kylo-spark-shell-client-v2-0.8.2.1-SNAPSHOT.jar!/com/thinkbiganalytics/spark/repl/SparkScriptEngine.class]: Instantiation of bean failed; nested exception is java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of org/apache/spark/util/ChildFirstURLClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for the method's defining class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type org/slf4j/ILoggerFactory used in the signature; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'transformService' defined in com.thinkbiganalytics.spark.SparkShellApp: Unsatisfied dependency expressed through constructor argument with index 1 of type [com.thinkbiganalytics.spark.repl.SparkScriptEngine]: Error creating bean with name 'sparkScriptEngine' defined in URL [jar:file:/opt/kylo/kylo-services/lib/app/kylo-spark-shell-client-v2-0.8.2.1-SNAPSHOT.jar!/com/thinkbiganalytics/spark/repl/SparkScriptEngine.class]: Instantiation of bean failed; nested exception is java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of org/apache/spark/util/ChildFirstURLClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for the method's defining class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type org/slf4j/ILoggerFactory used in the signature; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'sparkScriptEngine' defined in URL [jar:file:/opt/kylo/kylo-services/lib/app/kylo-spark-shell-client-v2-0.8.2.1-SNAPSHOT.jar!/com/thinkbiganalytics/spark/repl/SparkScriptEngine.class]: Instantiation of bean failed; nested exception is java.lang.LinkageError: loader constraint violation: when resolving method "org.slf4j.impl.StaticLoggerBinder.getLoggerFactory()Lorg/slf4j/ILoggerFactory;" the class loader (instance of org/apache/spark/util/ChildFirstURLClassLoader) of the current class, org/slf4j/LoggerFactory, and the class loader (instance of sun/misc/Launcher$AppClassLoader) for the method's defining class, org/slf4j/impl/StaticLoggerBinder, have different Class objects for the type org/slf4j/ILoggerFactory used in the signature

It seems that there are some version conflicts with slf4j. At least Kylo itself and Spark uses different versions of slf4j. I'll be grateful if someone sheds light on how Kylo loads dependencies for all involved components, and how to handle our problem.

Also, it's interesting that error disappears after removing /opt/kylo/kylo-services/conf from from --driver-class-path from parameter inside run-kylo-spark-shell.sh. But in that case we also havn't any logs related to our initial problem.

We are running Kylo 0.8.2.1 with HDP 2.6.

[Greg Hart]

Hi Valentin,

What files do you have in your /opt/kylo/kylo-services/conf/ directory?

Could you attach your entire kylo-spark-shell.err file?

[Valentin Polezhaev]

Hello Greg, 

logs and conf attached.

[Greg Hart]

Hmm, the Kylo Spark Shell doesn't include SLF4j and instead uses Spark's version. All of its dependencies are in the /opt/kylo/kylo-services/lib/app/kylo-spark-shell-client-v2-0.8.2.1-SNAPSHOT.jar file. It's possible you have different SLF4j versions in Hive and Spark?

So if you remove /opt/kylo/kylo-services/conf from the --driver-class-path and restart kylo-spark-shell, what does your kylo-spark-shell.err file look like?

[Valentin Polezhaev]

Hi Greg,

I don't know anything about possible slf4j version conflicts for Hive and Spark, but both Hive and Spark are from HDP 2.6. We havn't any problems with them yet. Can you give some recommendations on how to diagnose possible conflicts? Manual investigation of all Hive and Spark jars seems very hard.

kylo-spark-shell.err after /opt/kylo/kylo-services/conf removed from the --driver-class-path attached.

Thanks.

[Valentin Polezhaev]

We log all loaded by java classes, here listed classes related to slf4j:

[Loaded org.slf4j.ILoggerFactory from file:/home/kylo/.ivy2/jars/org.slf4j_slf4j-api-1.7.5.jar]

[Loaded org.slf4j.ILoggerFactory from file:/usr/hdp/2.6.1.0-129/spark2/jars/slf4j-api-1.7.16.jar]

[Loaded org.apache.commons.logging.impl.SLF4JLogFactory from file:/usr/hdp/2.6.1.0-129/spark2/jars/jcl-over-slf4j-1.7.16.jar]

[Loaded org.apache.commons.logging.impl.SLF4JLocationAwareLog from file:/usr/hdp/2.6.1.0-129/spark2/jars/jcl-over-slf4j-1.7.16.jar]

[Loaded org.apache.commons.logging.impl.SLF4JLog from file:/usr/hdp/2.6.1.0-129/spark2/jars/jcl-over-slf4j-1.7.16.jar]

[Loaded org.slf4j.Logger from file:/home/kylo/.ivy2/jars/org.slf4j_slf4j-api-1.7.5.jar]

[Loaded org.slf4j.LoggerFactory from file:/home/kylo/.ivy2/jars/org.slf4j_slf4j-api-1.7.5.jar]

[Loaded org.slf4j.helpers.SubstituteLoggerFactory from file:/home/kylo/.ivy2/jars/org.slf4j_slf4j-api-1.7.5.jar]

[Loaded org.slf4j.helpers.NOPLoggerFactory from file:/home/kylo/.ivy2/jars/org.slf4j_slf4j-api-1.7.5.jar]

[Loaded org.slf4j.spi.LoggerFactoryBinder from file:/usr/hdp/2.6.1.0-129/spark2/jars/slf4j-api-1.7.16.jar]

[Loaded org.slf4j.impl.StaticLoggerBinder from file:/usr/hdp/2.6.1.0-129/spark2/jars/slf4j-log4j12-1.7.16.jar]

[Loaded org.slf4j.impl.Log4jLoggerFactory from file:/usr/hdp/2.6.1.0-129/spark2/jars/slf4j-log4j12-1.7.16.jar]

[Loaded org.slf4j.Logger from file:/usr/hdp/2.6.1.0-129/spark2/jars/slf4j-api-1.7.16.jar]

[Loaded org.slf4j.spi.LocationAwareLogger from file:/usr/hdp/2.6.1.0-129/spark2/jars/slf4j-api-1.7.16.jar]

[Loaded org.slf4j.helpers.NamedLoggerBase from file:/usr/hdp/2.6.1.0-129/spark2/jars/slf4j-api-1.7.16.jar]

[Loaded org.slf4j.helpers.MarkerIgnoringBase from file:/usr/hdp/2.6.1.0-129/spark2/jars/slf4j-api-1.7.16.jar]

[Loaded org.slf4j.impl.Log4jLoggerAdapter from file:/usr/hdp/2.6.1.0-129/spark2/jars/slf4j-log4j12-1.7.16.jar]

At least first two lines show there are two versions of slf4j-api. Can it be a problem? If yes, how to fix it?

[Valentin Polezhaev]

And, finally, Kylo is built by ourselves (using provided isntructions) on Ubuntu Server 16.

[Valentin Polezhaev]

We have found issue and fix it. Problem was in com.databricks#spark-avro_2.11;3.2.0 package, which also includes self4j 1.7.5 in addition to Spark's 1.7.16. Kylo highlights problem as it try to instantiate loggers.