org.scalatest.exceptions.TestFailedException: spark-submit returned with exit code 1. Command line: './bin/spark-submit' '--name' 'prepare testing tables' '--master' 'local[2]' '--conf' 'spark.ui.enabled=false' '--conf' 'spark.master.rest.enabled=false' '--conf' 'spark.sql.warehouse.dir=/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09' '--conf' 'spark.sql.test.version.index=2' '--driver-java-options' '-Dderby.system.home=/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09' '/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py' 2018-08-15 03:23:57.289 - stderr> SLF4J: Class path contains multiple SLF4J bindings. 2018-08-15 03:23:57.289 - stderr> SLF4J: Found binding in [jar:file:/tmp/test-spark/spark-2.3.1/jars/slf4j-log4j12-1.7.16.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2018-08-15 03:23:57.289 - stderr> SLF4J: Found binding in [jar:file:/home/sparkivy/per-executor-caches/3/.ivy2/cache/org.slf4j/slf4j-log4j12/jars/slf4j-log4j12-1.7.16.jar!/org/slf4j/impl/StaticLoggerBinder.class] 2018-08-15 03:23:57.289 - stderr> SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation. 2018-08-15 03:23:57.289 - stderr> SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory] 2018-08-15 03:23:57.886 - stdout> 2018-08-15 03:23:57 WARN NativeCodeLoader:62 - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable 2018-08-15 03:23:58.607 - stdout> 2018-08-15 03:23:58 INFO SparkContext:54 - Running Spark version 2.3.1 2018-08-15 03:23:58.628 - stdout> 2018-08-15 03:23:58 INFO SparkContext:54 - Submitted application: prepare testing tables 2018-08-15 03:23:58.695 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - Changing view acls to: jenkins 2018-08-15 03:23:58.696 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - Changing modify acls to: jenkins 2018-08-15 03:23:58.696 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - Changing view acls groups to: 2018-08-15 03:23:58.696 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - Changing modify acls groups to: 2018-08-15 03:23:58.697 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - SecurityManager: authentication disabled; ui acls disabled; users with view permissions: Set(jenkins); groups with view permissions: Set(); users with modify permissions: Set(jenkins); groups with modify permissions: Set() 2018-08-15 03:23:58.978 - stdout> 2018-08-15 03:23:58 INFO Utils:54 - Successfully started service 'sparkDriver' on port 44665. 2018-08-15 03:23:59.001 - stdout> 2018-08-15 03:23:59 INFO SparkEnv:54 - Registering MapOutputTracker 2018-08-15 03:23:59.019 - stdout> 2018-08-15 03:23:59 INFO SparkEnv:54 - Registering BlockManagerMaster 2018-08-15 03:23:59.022 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMasterEndpoint:54 - Using org.apache.spark.storage.DefaultTopologyMapper for getting topology information 2018-08-15 03:23:59.022 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMasterEndpoint:54 - BlockManagerMasterEndpoint up 2018-08-15 03:23:59.031 - stdout> 2018-08-15 03:23:59 INFO DiskBlockManager:54 - Created local directory at /tmp/blockmgr-0273eede-9884-49b1-ad1d-766ddb9df8af 2018-08-15 03:23:59.054 - stdout> 2018-08-15 03:23:59 INFO MemoryStore:54 - MemoryStore started with capacity 366.3 MB 2018-08-15 03:23:59.071 - stdout> 2018-08-15 03:23:59 INFO SparkEnv:54 - Registering OutputCommitCoordinator 2018-08-15 03:23:59.373 - stdout> 2018-08-15 03:23:59 INFO SparkContext:54 - Added file file:/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py at file:/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py with timestamp 1534328639373 2018-08-15 03:23:59.375 - stdout> 2018-08-15 03:23:59 INFO Utils:54 - Copying /home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py to /tmp/spark-aa5a7c2b-82c1-448e-a2e1-fb8dfc09cc6a/userFiles-77f99d7d-8f2b-481c-be86-6980f98e961e/test2398271731702526479.py 2018-08-15 03:23:59.436 - stdout> 2018-08-15 03:23:59 INFO Executor:54 - Starting executor ID driver on host localhost 2018-08-15 03:23:59.454 - stdout> 2018-08-15 03:23:59 INFO Utils:54 - Successfully started service 'org.apache.spark.network.netty.NettyBlockTransferService' on port 35652. 2018-08-15 03:23:59.455 - stdout> 2018-08-15 03:23:59 INFO NettyBlockTransferService:54 - Server created on amp-jenkins-worker-04.amp:35652 2018-08-15 03:23:59.457 - stdout> 2018-08-15 03:23:59 INFO BlockManager:54 - Using org.apache.spark.storage.RandomBlockReplicationPolicy for block replication policy 2018-08-15 03:23:59.483 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMaster:54 - Registering BlockManager BlockManagerId(driver, amp-jenkins-worker-04.amp, 35652, None) 2018-08-15 03:23:59.486 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMasterEndpoint:54 - Registering block manager amp-jenkins-worker-04.amp:35652 with 366.3 MB RAM, BlockManagerId(driver, amp-jenkins-worker-04.amp, 35652, None) 2018-08-15 03:23:59.49 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMaster:54 - Registered BlockManager BlockManagerId(driver, amp-jenkins-worker-04.amp, 35652, None) 2018-08-15 03:23:59.49 - stdout> 2018-08-15 03:23:59 INFO BlockManager:54 - Initialized BlockManager: BlockManagerId(driver, amp-jenkins-worker-04.amp, 35652, None) 2018-08-15 03:23:59.679 - stdout> 2018-08-15 03:23:59 INFO log:192 - Logging initialized @2983ms 2018-08-15 03:23:59.846 - stdout> 2018-08-15 03:23:59 INFO SharedState:54 - loading hive config file: file:/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/sql/hive/target/scala-2.11/test-classes/hive-site.xml 2018-08-15 03:23:59.88 - stdout> 2018-08-15 03:23:59 INFO SharedState:54 - Setting hive.metastore.warehouse.dir ('null') to the value of spark.sql.warehouse.dir ('/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09'). 2018-08-15 03:23:59.881 - stdout> 2018-08-15 03:23:59 INFO SharedState:54 - Warehouse path is '/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09'. 2018-08-15 03:24:00.344 - stdout> 2018-08-15 03:24:00 INFO StateStoreCoordinatorRef:54 - Registered StateStoreCoordinator endpoint 2018-08-15 03:24:00.715 - stdout> 2018-08-15 03:24:00 INFO HiveUtils:54 - Initializing HiveMetastoreConnection version 1.2.1 using Spark classes. 2018-08-15 03:24:01.302 - stdout> 2018-08-15 03:24:01 INFO HiveMetaStore:589 - 0: Opening raw store with implemenation class:org.apache.hadoop.hive.metastore.ObjectStore 2018-08-15 03:24:01.327 - stdout> 2018-08-15 03:24:01 INFO ObjectStore:289 - ObjectStore, initialize called 2018-08-15 03:24:01.4 - stdout> 2018-08-15 03:24:01 WARN General:96 - Plugin (Bundle) "org.datanucleus.api.jdo" is already registered. Ensure you dont have multiple JAR versions of the same plugin in the classpath. The URL "file:/home/sparkivy/per-executor-caches/3/.ivy2/cache/org.datanucleus/datanucleus-api-jdo/jars/datanucleus-api-jdo-3.2.6.jar" is already registered, and you are trying to register an identical plugin located at URL "file:/tmp/test-spark/spark-2.3.1/jars/datanucleus-api-jdo-3.2.6.jar." 2018-08-15 03:24:01.422 - stdout> 2018-08-15 03:24:01 WARN General:96 - Plugin (Bundle) "org.datanucleus.store.rdbms" is already registered. Ensure you dont have multiple JAR versions of the same plugin in the classpath. The URL "file:/tmp/test-spark/spark-2.3.1/jars/datanucleus-rdbms-3.2.9.jar" is already registered, and you are trying to register an identical plugin located at URL "file:/home/sparkivy/per-executor-caches/3/.ivy2/cache/org.datanucleus/datanucleus-rdbms/jars/datanucleus-rdbms-3.2.9.jar." 2018-08-15 03:24:01.44 - stdout> 2018-08-15 03:24:01 WARN General:96 - Plugin (Bundle) "org.datanucleus" is already registered. Ensure you dont have multiple JAR versions of the same plugin in the classpath. The URL "file:/home/sparkivy/per-executor-caches/3/.ivy2/cache/org.datanucleus/datanucleus-core/jars/datanucleus-core-3.2.10.jar" is already registered, and you are trying to register an identical plugin located at URL "file:/tmp/test-spark/spark-2.3.1/jars/datanucleus-core-3.2.10.jar." 2018-08-15 03:24:01.459 - stdout> 2018-08-15 03:24:01 INFO Persistence:77 - Property hive.metastore.integral.jdo.pushdown unknown - will be ignored 2018-08-15 03:24:01.459 - stdout> 2018-08-15 03:24:01 INFO Persistence:77 - Property datanucleus.cache.level2 unknown - will be ignored 2018-08-15 03:24:04.48 - stdout> 2018-08-15 03:24:04 INFO ObjectStore:370 - Setting MetaStore object pin classes with hive.metastore.cache.pinobjtypes="Table,StorageDescriptor,SerDeInfo,Partition,Database,Type,FieldSchema,Order" 2018-08-15 03:24:05.704 - stdout> 2018-08-15 03:24:05 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MFieldSchema" is tagged as "embedded-only" so does not have its own datastore table. 2018-08-15 03:24:05.705 - stdout> 2018-08-15 03:24:05 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MOrder" is tagged as "embedded-only" so does not have its own datastore table. 2018-08-15 03:24:05.862 - stdout> 2018-08-15 03:24:05 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MFieldSchema" is tagged as "embedded-only" so does not have its own datastore table. 2018-08-15 03:24:05.863 - stdout> 2018-08-15 03:24:05 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MOrder" is tagged as "embedded-only" so does not have its own datastore table. 2018-08-15 03:24:05.938 - stdout> 2018-08-15 03:24:05 INFO Query:77 - Reading in results for query "org.datanucleus.store.rdbms.query.SQLQuery@0" since the connection used is closing 2018-08-15 03:24:05.939 - stdout> 2018-08-15 03:24:05 INFO MetaStoreDirectSql:139 - Using direct SQL, underlying DB is DERBY 2018-08-15 03:24:05.942 - stdout> 2018-08-15 03:24:05 INFO ObjectStore:272 - Initialized ObjectStore 2018-08-15 03:24:06.123 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:663 - Added admin role in metastore 2018-08-15 03:24:06.124 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:672 - Added public role in metastore 2018-08-15 03:24:06.167 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:712 - No user is added in admin role, since config is empty 2018-08-15 03:24:06.26 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:746 - 0: get_all_databases 2018-08-15 03:24:06.261 - stdout> 2018-08-15 03:24:06 INFO audit:371 - ugi=jenkins ip=unknown-ip-addr cmd=get_all_databases 2018-08-15 03:24:06.28 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:746 - 0: get_functions: db=default pat=* 2018-08-15 03:24:06.28 - stdout> 2018-08-15 03:24:06 INFO audit:371 - ugi=jenkins ip=unknown-ip-addr cmd=get_functions: db=default pat=* 2018-08-15 03:24:06.281 - stdout> 2018-08-15 03:24:06 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MResourceUri" is tagged as "embedded-only" so does not have its own datastore table. 2018-08-15 03:24:06.339 - stdout> 2018-08-15 03:24:06 INFO SessionState:641 - Created local directory: /tmp/8395badc-93a6-4313-8f97-2ceb9f31f7e9_resources 2018-08-15 03:24:06.343 - stdout> 2018-08-15 03:24:06 INFO SessionState:641 - Created HDFS directory: /tmp/hive/jenkins/8395badc-93a6-4313-8f97-2ceb9f31f7e9 2018-08-15 03:24:06.347 - stdout> 2018-08-15 03:24:06 INFO SessionState:641 - Created local directory: /tmp/jenkins/8395badc-93a6-4313-8f97-2ceb9f31f7e9 2018-08-15 03:24:06.351 - stdout> 2018-08-15 03:24:06 INFO SessionState:641 - Created HDFS directory: /tmp/hive/jenkins/8395badc-93a6-4313-8f97-2ceb9f31f7e9/_tmp_space.db 2018-08-15 03:24:06.354 - stdout> 2018-08-15 03:24:06 INFO HiveClientImpl:54 - Warehouse location for Hive client (version 1.2.2) is /home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09 2018-08-15 03:24:06.361 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:746 - 0: get_database: default 2018-08-15 03:24:06.361 - stdout> 2018-08-15 03:24:06 INFO audit:371 - ugi=jenkins ip=unknown-ip-addr cmd=get_database: default 2018-08-15 03:24:06.365 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:746 - 0: get_database: global_temp 2018-08-15 03:24:06.365 - stdout> 2018-08-15 03:24:06 INFO audit:371 - ugi=jenkins ip=unknown-ip-addr cmd=get_database: global_temp 2018-08-15 03:24:06.366 - stdout> 2018-08-15 03:24:06 WARN ObjectStore:568 - Failed to get database global_temp, returning NoSuchObjectException 2018-08-15 03:24:07.667 - stdout> Traceback (most recent call last): 2018-08-15 03:24:07.667 - stdout> File "/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py", line 8, in <module> 2018-08-15 03:24:07.667 - stdout> spark.sql("create table data_source_tbl_{} using json as select 1 i".format(version_index)) 2018-08-15 03:24:07.667 - stdout> File "/tmp/test-spark/spark-2.3.1/python/lib/pyspark.zip/pyspark/sql/session.py", line 710, in sql 2018-08-15 03:24:07.667 - stdout> File "/tmp/test-spark/spark-2.3.1/python/lib/py4j-0.10.7-src.zip/py4j/java_gateway.py", line 1257, in __call__ 2018-08-15 03:24:07.668 - stdout> File "/tmp/test-spark/spark-2.3.1/python/lib/pyspark.zip/pyspark/sql/utils.py", line 63, in deco 2018-08-15 03:24:07.668 - stdout> File "/tmp/test-spark/spark-2.3.1/python/lib/py4j-0.10.7-src.zip/py4j/protocol.py", line 328, in get_return_value 2018-08-15 03:24:07.669 - stdout> py4j.protocol.Py4JJavaError: An error occurred while calling o27.sql. 2018-08-15 03:24:07.669 - stdout> : java.lang.ExceptionInInitializerError 2018-08-15 03:24:07.669 - stdout> at org.apache.spark.SparkContext.withScope(SparkContext.scala:693) 2018-08-15 03:24:07.669 - stdout> at org.apache.spark.SparkContext.parallelize(SparkContext.scala:710) 2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.execution.SparkStrategies.singleRowRdd$lzycompute(SparkStrategies.scala:404) 2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.execution.SparkStrategies.singleRowRdd(SparkStrategies.scala:404) 2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.execution.SparkStrategies$BasicOperators$.apply(SparkStrategies.scala:541) 2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$1.apply(QueryPlanner.scala:63) 2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$1.apply(QueryPlanner.scala:63) 2018-08-15 03:24:07.669 - stdout> at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:434) 2018-08-15 03:24:07.669 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:440) 2018-08-15 03:24:07.669 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:439) 2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner.plan(QueryPlanner.scala:93) 2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:78) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:75) 2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157) 2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157) 2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$class.foreach(Iterator.scala:893) 2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foreach(Iterator.scala:1336) 2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$class.foldLeft(TraversableOnce.scala:157) 2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foldLeft(Iterator.scala:1336) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:75) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:67) 2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:434) 2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:440) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner.plan(QueryPlanner.scala:93) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:78) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:75) 2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157) 2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157) 2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$class.foreach(Iterator.scala:893) 2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foreach(Iterator.scala:1336) 2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$class.foldLeft(TraversableOnce.scala:157) 2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foldLeft(Iterator.scala:1336) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:75) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:67) 2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:434) 2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:440) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner.plan(QueryPlanner.scala:93) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:78) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:75) 2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157) 2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157) 2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$class.foreach(Iterator.scala:893) 2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foreach(Iterator.scala:1336) 2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$class.foldLeft(TraversableOnce.scala:157) 2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foldLeft(Iterator.scala:1336) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:75) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:67) 2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:434) 2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:440) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner.plan(QueryPlanner.scala:93) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.execution.QueryExecution.sparkPlan$lzycompute(QueryExecution.scala:72) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.execution.QueryExecution.sparkPlan(QueryExecution.scala:68) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.execution.QueryExecution.executedPlan$lzycompute(QueryExecution.scala:77) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.execution.QueryExecution.executedPlan(QueryExecution.scala:77) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.Dataset.withAction(Dataset.scala:3249) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.Dataset.<init>(Dataset.scala:190) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.Dataset$.ofRows(Dataset.scala:75) 2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.SparkSession.sql(SparkSession.scala:641) 2018-08-15 03:24:07.67 - stdout> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) 2018-08-15 03:24:07.67 - stdout> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) 2018-08-15 03:24:07.671 - stdout> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) 2018-08-15 03:24:07.671 - stdout> at java.lang.reflect.Method.invoke(Method.java:497) 2018-08-15 03:24:07.671 - stdout> at py4j.reflection.MethodInvoker.invoke(MethodInvoker.java:244) 2018-08-15 03:24:07.671 - stdout> at py4j.reflection.ReflectionEngine.invoke(ReflectionEngine.java:357) 2018-08-15 03:24:07.671 - stdout> at py4j.Gateway.invoke(Gateway.java:282) 2018-08-15 03:24:07.671 - stdout> at py4j.commands.AbstractCommand.invokeMethod(AbstractCommand.java:132) 2018-08-15 03:24:07.671 - stdout> at py4j.commands.CallCommand.execute(CallCommand.java:79) 2018-08-15 03:24:07.671 - stdout> at py4j.GatewayConnection.run(GatewayConnection.java:238) 2018-08-15 03:24:07.671 - stdout> at java.lang.Thread.run(Thread.java:745) 2018-08-15 03:24:07.671 - stdout> Caused by: java.util.NoSuchElementException: key not found: groupId 2018-08-15 03:24:07.671 - stdout> at scala.collection.MapLike$class.default(MapLike.scala:228) 2018-08-15 03:24:07.671 - stdout> at scala.collection.AbstractMap.default(Map.scala:59) 2018-08-15 03:24:07.671 - stdout> at scala.collection.MapLike$class.apply(MapLike.scala:141) 2018-08-15 03:24:07.671 - stdout> at scala.collection.AbstractMap.apply(Map.scala:59) 2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.module.scala.JacksonModule$.version$lzycompute(JacksonModule.scala:27) 2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.module.scala.JacksonModule$.version(JacksonModule.scala:26) 2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.module.scala.JacksonModule$class.version(JacksonModule.scala:49) 2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.module.scala.DefaultScalaModule.version(DefaultScalaModule.scala:19) 2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.databind.ObjectMapper.registerModule(ObjectMapper.java:710) 2018-08-15 03:24:07.671 - stdout> at org.apache.spark.rdd.RDDOperationScope$.<init>(RDDOperationScope.scala:82) 2018-08-15 03:24:07.671 - stdout> at org.apache.spark.rdd.RDDOperationScope$.<clinit>(RDDOperationScope.scala) 2018-08-15 03:24:07.671 - stdout> ... 69 more 2018-08-15 03:24:07.671 - stdout> 2018-08-15 03:24:07.721 - stdout> 2018-08-15 03:24:07 INFO SparkContext:54 - Invoking stop() from shutdown hook 2018-08-15 03:24:07.734 - stdout> 2018-08-15 03:24:07 INFO MapOutputTrackerMasterEndpoint:54 - MapOutputTrackerMasterEndpoint stopped! 2018-08-15 03:24:07.74 - stdout> 2018-08-15 03:24:07 INFO MemoryStore:54 - MemoryStore cleared 2018-08-15 03:24:07.741 - stdout> 2018-08-15 03:24:07 INFO BlockManager:54 - BlockManager stopped 2018-08-15 03:24:07.749 - stdout> 2018-08-15 03:24:07 INFO BlockManagerMaster:54 - BlockManagerMaster stopped 2018-08-15 03:24:07.754 - stdout> 2018-08-15 03:24:07 INFO OutputCommitCoordinator$OutputCommitCoordinatorEndpoint:54 - OutputCommitCoordinator stopped! 2018-08-15 03:24:07.756 - stdout> 2018-08-15 03:24:07 INFO SparkContext:54 - Successfully stopped SparkContext 2018-08-15 03:24:07.756 - stdout> 2018-08-15 03:24:07 INFO ShutdownHookManager:54 - Shutdown hook called 2018-08-15 03:24:07.757 - stdout> 2018-08-15 03:24:07 INFO ShutdownHookManager:54 - Deleting directory /tmp/spark-8a143ae0-75b5-4aaf-a5eb-0a39af1c3222 2018-08-15 03:24:07.758 - stdout> 2018-08-15 03:24:07 INFO ShutdownHookManager:54 - Deleting directory /tmp/spark-aa5a7c2b-82c1-448e-a2e1-fb8dfc09cc6a/pyspark-d66c12f4-f62b-4a62-a331-b42a0df397cd 2018-08-15 03:24:07.758 - stdout> 2018-08-15 03:24:07 INFO ShutdownHookManager:54 - Deleting directory /tmp/spark-aa5a7c2b-82c1-448e-a2e1-fb8dfc09cc6a
sbt.ForkMain$ForkError: org.scalatest.exceptions.TestFailedException: spark-submit returned with exit code 1.
Command line: './bin/spark-submit' '--name' 'prepare testing tables' '--master' 'local[2]' '--conf' 'spark.ui.enabled=false' '--conf' 'spark.master.rest.enabled=false' '--conf' 'spark.sql.warehouse.dir=/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09' '--conf' 'spark.sql.test.version.index=2' '--driver-java-options' '-Dderby.system.home=/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09' '/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py'
2018-08-15 03:23:57.289 - stderr> SLF4J: Class path contains multiple SLF4J bindings.
2018-08-15 03:23:57.289 - stderr> SLF4J: Found binding in [jar:file:/tmp/test-spark/spark-2.3.1/jars/slf4j-log4j12-1.7.16.jar!/org/slf4j/impl/StaticLoggerBinder.class]
2018-08-15 03:23:57.289 - stderr> SLF4J: Found binding in [jar:file:/home/sparkivy/per-executor-caches/3/.ivy2/cache/org.slf4j/slf4j-log4j12/jars/slf4j-log4j12-1.7.16.jar!/org/slf4j/impl/StaticLoggerBinder.class]
2018-08-15 03:23:57.289 - stderr> SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
2018-08-15 03:23:57.289 - stderr> SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory]
2018-08-15 03:23:57.886 - stdout> 2018-08-15 03:23:57 WARN NativeCodeLoader:62 - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2018-08-15 03:23:58.607 - stdout> 2018-08-15 03:23:58 INFO SparkContext:54 - Running Spark version 2.3.1
2018-08-15 03:23:58.628 - stdout> 2018-08-15 03:23:58 INFO SparkContext:54 - Submitted application: prepare testing tables
2018-08-15 03:23:58.695 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - Changing view acls to: jenkins
2018-08-15 03:23:58.696 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - Changing modify acls to: jenkins
2018-08-15 03:23:58.696 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - Changing view acls groups to:
2018-08-15 03:23:58.696 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - Changing modify acls groups to:
2018-08-15 03:23:58.697 - stdout> 2018-08-15 03:23:58 INFO SecurityManager:54 - SecurityManager: authentication disabled; ui acls disabled; users with view permissions: Set(jenkins); groups with view permissions: Set(); users with modify permissions: Set(jenkins); groups with modify permissions: Set()
2018-08-15 03:23:58.978 - stdout> 2018-08-15 03:23:58 INFO Utils:54 - Successfully started service 'sparkDriver' on port 44665.
2018-08-15 03:23:59.001 - stdout> 2018-08-15 03:23:59 INFO SparkEnv:54 - Registering MapOutputTracker
2018-08-15 03:23:59.019 - stdout> 2018-08-15 03:23:59 INFO SparkEnv:54 - Registering BlockManagerMaster
2018-08-15 03:23:59.022 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMasterEndpoint:54 - Using org.apache.spark.storage.DefaultTopologyMapper for getting topology information
2018-08-15 03:23:59.022 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMasterEndpoint:54 - BlockManagerMasterEndpoint up
2018-08-15 03:23:59.031 - stdout> 2018-08-15 03:23:59 INFO DiskBlockManager:54 - Created local directory at /tmp/blockmgr-0273eede-9884-49b1-ad1d-766ddb9df8af
2018-08-15 03:23:59.054 - stdout> 2018-08-15 03:23:59 INFO MemoryStore:54 - MemoryStore started with capacity 366.3 MB
2018-08-15 03:23:59.071 - stdout> 2018-08-15 03:23:59 INFO SparkEnv:54 - Registering OutputCommitCoordinator
2018-08-15 03:23:59.373 - stdout> 2018-08-15 03:23:59 INFO SparkContext:54 - Added file file:/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py at file:/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py with timestamp 1534328639373
2018-08-15 03:23:59.375 - stdout> 2018-08-15 03:23:59 INFO Utils:54 - Copying /home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py to /tmp/spark-aa5a7c2b-82c1-448e-a2e1-fb8dfc09cc6a/userFiles-77f99d7d-8f2b-481c-be86-6980f98e961e/test2398271731702526479.py
2018-08-15 03:23:59.436 - stdout> 2018-08-15 03:23:59 INFO Executor:54 - Starting executor ID driver on host localhost
2018-08-15 03:23:59.454 - stdout> 2018-08-15 03:23:59 INFO Utils:54 - Successfully started service 'org.apache.spark.network.netty.NettyBlockTransferService' on port 35652.
2018-08-15 03:23:59.455 - stdout> 2018-08-15 03:23:59 INFO NettyBlockTransferService:54 - Server created on amp-jenkins-worker-04.amp:35652
2018-08-15 03:23:59.457 - stdout> 2018-08-15 03:23:59 INFO BlockManager:54 - Using org.apache.spark.storage.RandomBlockReplicationPolicy for block replication policy
2018-08-15 03:23:59.483 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMaster:54 - Registering BlockManager BlockManagerId(driver, amp-jenkins-worker-04.amp, 35652, None)
2018-08-15 03:23:59.486 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMasterEndpoint:54 - Registering block manager amp-jenkins-worker-04.amp:35652 with 366.3 MB RAM, BlockManagerId(driver, amp-jenkins-worker-04.amp, 35652, None)
2018-08-15 03:23:59.49 - stdout> 2018-08-15 03:23:59 INFO BlockManagerMaster:54 - Registered BlockManager BlockManagerId(driver, amp-jenkins-worker-04.amp, 35652, None)
2018-08-15 03:23:59.49 - stdout> 2018-08-15 03:23:59 INFO BlockManager:54 - Initialized BlockManager: BlockManagerId(driver, amp-jenkins-worker-04.amp, 35652, None)
2018-08-15 03:23:59.679 - stdout> 2018-08-15 03:23:59 INFO log:192 - Logging initialized @2983ms
2018-08-15 03:23:59.846 - stdout> 2018-08-15 03:23:59 INFO SharedState:54 - loading hive config file: file:/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/sql/hive/target/scala-2.11/test-classes/hive-site.xml
2018-08-15 03:23:59.88 - stdout> 2018-08-15 03:23:59 INFO SharedState:54 - Setting hive.metastore.warehouse.dir ('null') to the value of spark.sql.warehouse.dir ('/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09').
2018-08-15 03:23:59.881 - stdout> 2018-08-15 03:23:59 INFO SharedState:54 - Warehouse path is '/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09'.
2018-08-15 03:24:00.344 - stdout> 2018-08-15 03:24:00 INFO StateStoreCoordinatorRef:54 - Registered StateStoreCoordinator endpoint
2018-08-15 03:24:00.715 - stdout> 2018-08-15 03:24:00 INFO HiveUtils:54 - Initializing HiveMetastoreConnection version 1.2.1 using Spark classes.
2018-08-15 03:24:01.302 - stdout> 2018-08-15 03:24:01 INFO HiveMetaStore:589 - 0: Opening raw store with implemenation class:org.apache.hadoop.hive.metastore.ObjectStore
2018-08-15 03:24:01.327 - stdout> 2018-08-15 03:24:01 INFO ObjectStore:289 - ObjectStore, initialize called
2018-08-15 03:24:01.4 - stdout> 2018-08-15 03:24:01 WARN General:96 - Plugin (Bundle) "org.datanucleus.api.jdo" is already registered. Ensure you dont have multiple JAR versions of the same plugin in the classpath. The URL "file:/home/sparkivy/per-executor-caches/3/.ivy2/cache/org.datanucleus/datanucleus-api-jdo/jars/datanucleus-api-jdo-3.2.6.jar" is already registered, and you are trying to register an identical plugin located at URL "file:/tmp/test-spark/spark-2.3.1/jars/datanucleus-api-jdo-3.2.6.jar."
2018-08-15 03:24:01.422 - stdout> 2018-08-15 03:24:01 WARN General:96 - Plugin (Bundle) "org.datanucleus.store.rdbms" is already registered. Ensure you dont have multiple JAR versions of the same plugin in the classpath. The URL "file:/tmp/test-spark/spark-2.3.1/jars/datanucleus-rdbms-3.2.9.jar" is already registered, and you are trying to register an identical plugin located at URL "file:/home/sparkivy/per-executor-caches/3/.ivy2/cache/org.datanucleus/datanucleus-rdbms/jars/datanucleus-rdbms-3.2.9.jar."
2018-08-15 03:24:01.44 - stdout> 2018-08-15 03:24:01 WARN General:96 - Plugin (Bundle) "org.datanucleus" is already registered. Ensure you dont have multiple JAR versions of the same plugin in the classpath. The URL "file:/home/sparkivy/per-executor-caches/3/.ivy2/cache/org.datanucleus/datanucleus-core/jars/datanucleus-core-3.2.10.jar" is already registered, and you are trying to register an identical plugin located at URL "file:/tmp/test-spark/spark-2.3.1/jars/datanucleus-core-3.2.10.jar."
2018-08-15 03:24:01.459 - stdout> 2018-08-15 03:24:01 INFO Persistence:77 - Property hive.metastore.integral.jdo.pushdown unknown - will be ignored
2018-08-15 03:24:01.459 - stdout> 2018-08-15 03:24:01 INFO Persistence:77 - Property datanucleus.cache.level2 unknown - will be ignored
2018-08-15 03:24:04.48 - stdout> 2018-08-15 03:24:04 INFO ObjectStore:370 - Setting MetaStore object pin classes with hive.metastore.cache.pinobjtypes="Table,StorageDescriptor,SerDeInfo,Partition,Database,Type,FieldSchema,Order"
2018-08-15 03:24:05.704 - stdout> 2018-08-15 03:24:05 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MFieldSchema" is tagged as "embedded-only" so does not have its own datastore table.
2018-08-15 03:24:05.705 - stdout> 2018-08-15 03:24:05 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MOrder" is tagged as "embedded-only" so does not have its own datastore table.
2018-08-15 03:24:05.862 - stdout> 2018-08-15 03:24:05 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MFieldSchema" is tagged as "embedded-only" so does not have its own datastore table.
2018-08-15 03:24:05.863 - stdout> 2018-08-15 03:24:05 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MOrder" is tagged as "embedded-only" so does not have its own datastore table.
2018-08-15 03:24:05.938 - stdout> 2018-08-15 03:24:05 INFO Query:77 - Reading in results for query "org.datanucleus.store.rdbms.query.SQLQuery@0" since the connection used is closing
2018-08-15 03:24:05.939 - stdout> 2018-08-15 03:24:05 INFO MetaStoreDirectSql:139 - Using direct SQL, underlying DB is DERBY
2018-08-15 03:24:05.942 - stdout> 2018-08-15 03:24:05 INFO ObjectStore:272 - Initialized ObjectStore
2018-08-15 03:24:06.123 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:663 - Added admin role in metastore
2018-08-15 03:24:06.124 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:672 - Added public role in metastore
2018-08-15 03:24:06.167 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:712 - No user is added in admin role, since config is empty
2018-08-15 03:24:06.26 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:746 - 0: get_all_databases
2018-08-15 03:24:06.261 - stdout> 2018-08-15 03:24:06 INFO audit:371 - ugi=jenkins ip=unknown-ip-addr cmd=get_all_databases
2018-08-15 03:24:06.28 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:746 - 0: get_functions: db=default pat=*
2018-08-15 03:24:06.28 - stdout> 2018-08-15 03:24:06 INFO audit:371 - ugi=jenkins ip=unknown-ip-addr cmd=get_functions: db=default pat=*
2018-08-15 03:24:06.281 - stdout> 2018-08-15 03:24:06 INFO Datastore:77 - The class "org.apache.hadoop.hive.metastore.model.MResourceUri" is tagged as "embedded-only" so does not have its own datastore table.
2018-08-15 03:24:06.339 - stdout> 2018-08-15 03:24:06 INFO SessionState:641 - Created local directory: /tmp/8395badc-93a6-4313-8f97-2ceb9f31f7e9_resources
2018-08-15 03:24:06.343 - stdout> 2018-08-15 03:24:06 INFO SessionState:641 - Created HDFS directory: /tmp/hive/jenkins/8395badc-93a6-4313-8f97-2ceb9f31f7e9
2018-08-15 03:24:06.347 - stdout> 2018-08-15 03:24:06 INFO SessionState:641 - Created local directory: /tmp/jenkins/8395badc-93a6-4313-8f97-2ceb9f31f7e9
2018-08-15 03:24:06.351 - stdout> 2018-08-15 03:24:06 INFO SessionState:641 - Created HDFS directory: /tmp/hive/jenkins/8395badc-93a6-4313-8f97-2ceb9f31f7e9/_tmp_space.db
2018-08-15 03:24:06.354 - stdout> 2018-08-15 03:24:06 INFO HiveClientImpl:54 - Warehouse location for Hive client (version 1.2.2) is /home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/warehouse-e5840286-37a0-43f6-8089-b5906e58aa09
2018-08-15 03:24:06.361 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:746 - 0: get_database: default
2018-08-15 03:24:06.361 - stdout> 2018-08-15 03:24:06 INFO audit:371 - ugi=jenkins ip=unknown-ip-addr cmd=get_database: default
2018-08-15 03:24:06.365 - stdout> 2018-08-15 03:24:06 INFO HiveMetaStore:746 - 0: get_database: global_temp
2018-08-15 03:24:06.365 - stdout> 2018-08-15 03:24:06 INFO audit:371 - ugi=jenkins ip=unknown-ip-addr cmd=get_database: global_temp
2018-08-15 03:24:06.366 - stdout> 2018-08-15 03:24:06 WARN ObjectStore:568 - Failed to get database global_temp, returning NoSuchObjectException
2018-08-15 03:24:07.667 - stdout> Traceback (most recent call last):
2018-08-15 03:24:07.667 - stdout> File "/home/jenkins/workspace/spark-master-test-sbt-hadoop-2.7/target/tmp/test2398271731702526479.py", line 8, in <module>
2018-08-15 03:24:07.667 - stdout> spark.sql("create table data_source_tbl_{} using json as select 1 i".format(version_index))
2018-08-15 03:24:07.667 - stdout> File "/tmp/test-spark/spark-2.3.1/python/lib/pyspark.zip/pyspark/sql/session.py", line 710, in sql
2018-08-15 03:24:07.667 - stdout> File "/tmp/test-spark/spark-2.3.1/python/lib/py4j-0.10.7-src.zip/py4j/java_gateway.py", line 1257, in __call__
2018-08-15 03:24:07.668 - stdout> File "/tmp/test-spark/spark-2.3.1/python/lib/pyspark.zip/pyspark/sql/utils.py", line 63, in deco
2018-08-15 03:24:07.668 - stdout> File "/tmp/test-spark/spark-2.3.1/python/lib/py4j-0.10.7-src.zip/py4j/protocol.py", line 328, in get_return_value
2018-08-15 03:24:07.669 - stdout> py4j.protocol.Py4JJavaError: An error occurred while calling o27.sql.
2018-08-15 03:24:07.669 - stdout> : java.lang.ExceptionInInitializerError
2018-08-15 03:24:07.669 - stdout> at org.apache.spark.SparkContext.withScope(SparkContext.scala:693)
2018-08-15 03:24:07.669 - stdout> at org.apache.spark.SparkContext.parallelize(SparkContext.scala:710)
2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.execution.SparkStrategies.singleRowRdd$lzycompute(SparkStrategies.scala:404)
2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.execution.SparkStrategies.singleRowRdd(SparkStrategies.scala:404)
2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.execution.SparkStrategies$BasicOperators$.apply(SparkStrategies.scala:541)
2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$1.apply(QueryPlanner.scala:63)
2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$1.apply(QueryPlanner.scala:63)
2018-08-15 03:24:07.669 - stdout> at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:434)
2018-08-15 03:24:07.669 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:440)
2018-08-15 03:24:07.669 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:439)
2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner.plan(QueryPlanner.scala:93)
2018-08-15 03:24:07.669 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:78)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:75)
2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157)
2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157)
2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$class.foreach(Iterator.scala:893)
2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foreach(Iterator.scala:1336)
2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$class.foldLeft(TraversableOnce.scala:157)
2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foldLeft(Iterator.scala:1336)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:75)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:67)
2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:434)
2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:440)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner.plan(QueryPlanner.scala:93)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:78)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:75)
2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157)
2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157)
2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$class.foreach(Iterator.scala:893)
2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foreach(Iterator.scala:1336)
2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$class.foldLeft(TraversableOnce.scala:157)
2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foldLeft(Iterator.scala:1336)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:75)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:67)
2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:434)
2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:440)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner.plan(QueryPlanner.scala:93)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:78)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2$$anonfun$apply$2.apply(QueryPlanner.scala:75)
2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157)
2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$$anonfun$foldLeft$1.apply(TraversableOnce.scala:157)
2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$class.foreach(Iterator.scala:893)
2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foreach(Iterator.scala:1336)
2018-08-15 03:24:07.67 - stdout> at scala.collection.TraversableOnce$class.foldLeft(TraversableOnce.scala:157)
2018-08-15 03:24:07.67 - stdout> at scala.collection.AbstractIterator.foldLeft(Iterator.scala:1336)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:75)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner$$anonfun$2.apply(QueryPlanner.scala:67)
2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.nextCur(Iterator.scala:434)
2018-08-15 03:24:07.67 - stdout> at scala.collection.Iterator$$anon$12.hasNext(Iterator.scala:440)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.catalyst.planning.QueryPlanner.plan(QueryPlanner.scala:93)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.execution.QueryExecution.sparkPlan$lzycompute(QueryExecution.scala:72)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.execution.QueryExecution.sparkPlan(QueryExecution.scala:68)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.execution.QueryExecution.executedPlan$lzycompute(QueryExecution.scala:77)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.execution.QueryExecution.executedPlan(QueryExecution.scala:77)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.Dataset.withAction(Dataset.scala:3249)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.Dataset.<init>(Dataset.scala:190)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.Dataset$.ofRows(Dataset.scala:75)
2018-08-15 03:24:07.67 - stdout> at org.apache.spark.sql.SparkSession.sql(SparkSession.scala:641)
2018-08-15 03:24:07.67 - stdout> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2018-08-15 03:24:07.67 - stdout> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
2018-08-15 03:24:07.671 - stdout> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
2018-08-15 03:24:07.671 - stdout> at java.lang.reflect.Method.invoke(Method.java:497)
2018-08-15 03:24:07.671 - stdout> at py4j.reflection.MethodInvoker.invoke(MethodInvoker.java:244)
2018-08-15 03:24:07.671 - stdout> at py4j.reflection.ReflectionEngine.invoke(ReflectionEngine.java:357)
2018-08-15 03:24:07.671 - stdout> at py4j.Gateway.invoke(Gateway.java:282)
2018-08-15 03:24:07.671 - stdout> at py4j.commands.AbstractCommand.invokeMethod(AbstractCommand.java:132)
2018-08-15 03:24:07.671 - stdout> at py4j.commands.CallCommand.execute(CallCommand.java:79)
2018-08-15 03:24:07.671 - stdout> at py4j.GatewayConnection.run(GatewayConnection.java:238)
2018-08-15 03:24:07.671 - stdout> at java.lang.Thread.run(Thread.java:745)
2018-08-15 03:24:07.671 - stdout> Caused by: java.util.NoSuchElementException: key not found: groupId
2018-08-15 03:24:07.671 - stdout> at scala.collection.MapLike$class.default(MapLike.scala:228)
2018-08-15 03:24:07.671 - stdout> at scala.collection.AbstractMap.default(Map.scala:59)
2018-08-15 03:24:07.671 - stdout> at scala.collection.MapLike$class.apply(MapLike.scala:141)
2018-08-15 03:24:07.671 - stdout> at scala.collection.AbstractMap.apply(Map.scala:59)
2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.module.scala.JacksonModule$.version$lzycompute(JacksonModule.scala:27)
2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.module.scala.JacksonModule$.version(JacksonModule.scala:26)
2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.module.scala.JacksonModule$class.version(JacksonModule.scala:49)
2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.module.scala.DefaultScalaModule.version(DefaultScalaModule.scala:19)
2018-08-15 03:24:07.671 - stdout> at com.fasterxml.jackson.databind.ObjectMapper.registerModule(ObjectMapper.java:710)
2018-08-15 03:24:07.671 - stdout> at org.apache.spark.rdd.RDDOperationScope$.<init>(RDDOperationScope.scala:82)
2018-08-15 03:24:07.671 - stdout> at org.apache.spark.rdd.RDDOperationScope$.<clinit>(RDDOperationScope.scala)
2018-08-15 03:24:07.671 - stdout> ... 69 more
2018-08-15 03:24:07.671 - stdout>
2018-08-15 03:24:07.721 - stdout> 2018-08-15 03:24:07 INFO SparkContext:54 - Invoking stop() from shutdown hook
2018-08-15 03:24:07.734 - stdout> 2018-08-15 03:24:07 INFO MapOutputTrackerMasterEndpoint:54 - MapOutputTrackerMasterEndpoint stopped!
2018-08-15 03:24:07.74 - stdout> 2018-08-15 03:24:07 INFO MemoryStore:54 - MemoryStore cleared
2018-08-15 03:24:07.741 - stdout> 2018-08-15 03:24:07 INFO BlockManager:54 - BlockManager stopped
2018-08-15 03:24:07.749 - stdout> 2018-08-15 03:24:07 INFO BlockManagerMaster:54 - BlockManagerMaster stopped
2018-08-15 03:24:07.754 - stdout> 2018-08-15 03:24:07 INFO OutputCommitCoordinator$OutputCommitCoordinatorEndpoint:54 - OutputCommitCoordinator stopped!
2018-08-15 03:24:07.756 - stdout> 2018-08-15 03:24:07 INFO SparkContext:54 - Successfully stopped SparkContext
2018-08-15 03:24:07.756 - stdout> 2018-08-15 03:24:07 INFO ShutdownHookManager:54 - Shutdown hook called
2018-08-15 03:24:07.757 - stdout> 2018-08-15 03:24:07 INFO ShutdownHookManager:54 - Deleting directory /tmp/spark-8a143ae0-75b5-4aaf-a5eb-0a39af1c3222
2018-08-15 03:24:07.758 - stdout> 2018-08-15 03:24:07 INFO ShutdownHookManager:54 - Deleting directory /tmp/spark-aa5a7c2b-82c1-448e-a2e1-fb8dfc09cc6a/pyspark-d66c12f4-f62b-4a62-a331-b42a0df397cd
2018-08-15 03:24:07.758 - stdout> 2018-08-15 03:24:07 INFO ShutdownHookManager:54 - Deleting directory /tmp/spark-aa5a7c2b-82c1-448e-a2e1-fb8dfc09cc6a
at org.scalatest.Assertions$class.newAssertionFailedException(Assertions.scala:528)
at org.scalatest.FunSuite.newAssertionFailedException(FunSuite.scala:1560)
at org.scalatest.Assertions$class.fail(Assertions.scala:1089)
at org.scalatest.FunSuite.fail(FunSuite.scala:1560)
at org.apache.spark.sql.hive.SparkSubmitTestUtils$class.runSparkSubmit(SparkSubmitTestUtils.scala:84)
at org.apache.spark.sql.hive.HiveExternalCatalogVersionsSuite.runSparkSubmit(HiveExternalCatalogVersionsSuite.scala:43)
at org.apache.spark.sql.hive.HiveExternalCatalogVersionsSuite$$anonfun$beforeAll$1.apply(HiveExternalCatalogVersionsSuite.scala:184)
at org.apache.spark.sql.hive.HiveExternalCatalogVersionsSuite$$anonfun$beforeAll$1.apply(HiveExternalCatalogVersionsSuite.scala:169)
at scala.collection.immutable.List.foreach(List.scala:392)
at org.apache.spark.sql.hive.HiveExternalCatalogVersionsSuite.beforeAll(HiveExternalCatalogVersionsSuite.scala:169)
at org.scalatest.BeforeAndAfterAll$class.liftedTree1$1(BeforeAndAfterAll.scala:212)
at org.scalatest.BeforeAndAfterAll$class.run(BeforeAndAfterAll.scala:210)
at org.apache.spark.SparkFunSuite.run(SparkFunSuite.scala:52)
at org.scalatest.tools.Framework.org$scalatest$tools$Framework$$runSuite(Framework.scala:314)
at org.scalatest.tools.Framework$ScalaTestTask.execute(Framework.scala:480)
at sbt.ForkMain$Run$2.call(ForkMain.java:296)
at sbt.ForkMain$Run$2.call(ForkMain.java:286)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)