microsoft / azure-tools-for-java

Azure tools for Java, including Azure Toolkits for Eclipse, IntelliJ and related projects.
Other
240 stars 161 forks source link

[Intellij][Spark on ADL] On PPE enviroment, Remote run cannot submit successfully #1793

Closed liyanp1987 closed 6 years ago

liyanp1987 commented 6 years ago

Repro Bits azure-toolkit-for-intellij-2018.1.PR.1743.07-13-2018

Repro Platform PPE

Repro Steps

  1. Remote run IO job to ADL cluster

Actual result It cannot submit successfully

Log Package and deploy the job to Spark cluster INFO: Begin uploading file /home/yp1/IdeaProjects/project0620/out/artifacts/project0620_DefaultArtifact/default_artifact.jar to Azure Datalake store adl://adlpspark03.caboaccountdogfood.net/SparkSubmission/2018/07/16/73853362-afd5-4a70-bebf-8a74357cbfc5/default_artifact.jar ... INFO: Upload to Azure Datalake store 67647 bytes successfully. LOG: 23544648 LOG: "D:\data\yarnnm\local\usercache\350a102a-d910-4538-8e7e-4ce6b905fa3f\appcache\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\wd\archive-java-spark-livy-2.3.0.zip\jdk1.8.0_144\bin\java" -Xmx128m -cp ""D:\data\yarnnm\local\usercache\350a102a-d910-4538-8e7e-4ce6b905fa3f\appcache\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\wd\archive-java-spark-livy-2.3.0.zip\spark\bin..\jars"*" org.apache.spark.launcher.Main org.apache.spark.deploy.SparkSubmit --class sample.SparkCore_WasbIOTest --conf spark.executor.instances=2 --conf spark.master=spark://BN4SCH101162724:4892 adl://adlpspark03.caboaccountdogfood.net/SparkSubmission/2018/07/16/73853362-afd5-4a70-bebf-8a74357cbfc5/default_artifact.jar LOG: Invalid switch - "data". LOG: log4j:WARN Continuable parsing error 2 and column 82 LOG: log4j:WARN Document root element "log4j:configuration", must match DOCTYPE root "null". LOG: log4j:WARN Continuable parsing error 2 and column 82 LOG: log4j:WARN Document is invalid: no grammar found. LOG: log4j: reset attribute= "". LOG: log4j: Threshold ="". LOG: log4j: Reading configuration from URL jar:file:/D:/data/yarnnm/local/usercache/350a102a-d910-4538-8e7e-4ce6b905fa3f/appcache/application_1530846519304_1039/container_e4861_1530846519304_1039_01_000002/wd/archive-java-spark-livy-2.3.0.zip/spark/jars/spark-core_2.11-2.3.0.jar!/org/apache/spark/log4j-defaults.properties LOG: log4j: Parsing for [root] with value=[INFO, console]. LOG: log4j: Level token is [INFO]. LOG: log4j: Category root set to INFO LOG: log4j: Parsing appender named "console". LOG: log4j: Parsing layout options for "console". LOG: log4j: Setting property [conversionPattern] to [%d{yy/MM/dd HH:mm:ss} %p %c{1}: %m%n]. LOG: log4j: End of parsing for "console". LOG: log4j: Setting property [target] to [System.err]. LOG: log4j: Parsed "console" options. LOG: log4j: Parsing for [org.spark_project.jetty] with value=[WARN]. LOG: log4j: Level token is [WARN]. LOG: log4j: Category org.spark_project.jetty set to WARN LOG: log4j: Handling log4j.additivity.org.spark_project.jetty=[null] LOG: log4j: Parsing for [parquet.CorruptStatistics] with value=[ERROR]. LOG: log4j: Level token is [ERROR]. LOG: log4j: Category parquet.CorruptStatistics set to ERROR LOG: log4j: Handling log4j.additivity.parquet.CorruptStatistics=[null] LOG: log4j: Parsing for [org.apache.hadoop.hive.metastore.RetryingHMSHandler] with value=[FATAL]. LOG: log4j: Level token is [FATAL]. LOG: log4j: Category org.apache.hadoop.hive.metastore.RetryingHMSHandler set to FATAL LOG: log4j: Handling log4j.additivity.org.apache.hadoop.hive.metastore.RetryingHMSHandler=[null] LOG: log4j: Parsing for [org.spark_project.jetty.util.component.AbstractLifeCycle] with value=[ERROR]. LOG: log4j: Level token is [ERROR]. LOG: log4j: Category org.spark_project.jetty.util.component.AbstractLifeCycle set to ERROR LOG: log4j: Handling log4j.additivity.org.spark_project.jetty.util.component.AbstractLifeCycle=[null] LOG: log4j: Parsing for [org.apache.spark.repl.SparkILoop$SparkILoopInterpreter] with value=[INFO]. LOG: log4j: Level token is [INFO]. LOG: log4j: Category org.apache.spark.repl.SparkILoop$SparkILoopInterpreter set to INFO LOG: log4j: Handling log4j.additivity.org.apache.spark.repl.SparkILoop$SparkILoopInterpreter=[null] LOG: log4j: Parsing for [org.apache.parquet.CorruptStatistics] with value=[ERROR]. LOG: log4j: Level token is [ERROR]. LOG: log4j: Category org.apache.parquet.CorruptStatistics set to ERROR LOG: log4j: Handling log4j.additivity.org.apache.parquet.CorruptStatistics=[null] LOG: log4j: Parsing for [org.apache.spark.repl.Main] with value=[WARN]. LOG: log4j: Level token is [WARN]. LOG: log4j: Category org.apache.spark.repl.Main set to WARN LOG: log4j: Handling log4j.additivity.org.apache.spark.repl.Main=[null] LOG: log4j: Parsing for [org.apache.spark.repl.SparkIMain$exprTyper] with value=[INFO]. LOG: log4j: Level token is [INFO]. LOG: log4j: Category org.apache.spark.repl.SparkIMain$exprTyper set to INFO LOG: log4j: Handling log4j.additivity.org.apache.spark.repl.SparkIMain$exprTyper=[null] LOG: log4j: Parsing for [org.apache.hadoop.hive.ql.exec.FunctionRegistry] with value=[ERROR]. LOG: log4j: Level token is [ERROR]. LOG: log4j: Category org.apache.hadoop.hive.ql.exec.FunctionRegistry set to ERROR LOG: log4j: Handling log4j.additivity.org.apache.hadoop.hive.ql.exec.FunctionRegistry=[null] LOG: log4j: Finished configuring. LOG: 18/07/15 23:54:48 WARN SparkConf: The configuration key 'spark.executor.port' has been deprecated as of Spark 2.0.0 and may be removed in the future. Not used any more LOG: d,07/15/2018 23:54:48,SecureStoreServiceClient,,SrcFile="TraceInfo.cpp" SrcFunc="SecureStoreService::Common::TraceInfo::TraceInfo" SrcLine="790" Pid="63804" Tid="44200" TS="0x01D41CD1E3454EBD" String1="HDFS Shim Initializing with ini file: cosmos.ini.flattened.ini,c=55A75F6B-6713-4FB2-8002-FCD1AD235345: Start SeInitializeEx" LOG: i,07/15/2018 23:54:48.729,Common,CommonLibMain,SrcFile="main.cpp" SrcFunc="apsdk::CommonInit" SrcLine="86" Pid="63804" Tid="44200" TS="0x01D41CD1E3454EBD" String1="CommonInit called at 2018-07-15T23:54:48.729L+7h, applicationDir=(null), defaultConfigName=cosmos.ini.flattened.ini, bootstrapConfigDir=(null)" LOG: i,07/15/2018 23:54:48.729,Common,Configuration,SrcFile="configuration.cpp" SrcFunc="apsdk::configuration::Configuration::PreInitialize" SrcLine="138" Pid="63804" Tid="44200" TS="0x01D41CD1E3454EBD" String1="CConfiguration::Preinitialize called at 2018-07-15T23:54:48.729L+7h" LOG: i,07/15/2018 23:54:48.730,Common,ConfigurationManager,SrcFile="configurationmanager.cpp" SrcFunc="apsdk::configuration::ConfigurationManager::ProcessOverrides" SrcLine="228" Pid="63804" Tid="44200" TS="0x01D41CD1E34575E5" String1="Processing overrides at 2018-07-15T23:54:48.730L+7h" LOG: i,07/15/2018 23:54:48.730,Common,ConfigurationCollection,SrcFile="configurationcollection.cpp" SrcFunc="apsdk::configuration::internal::ConfigurationCollection::Init" SrcLine="110" Pid="63804" Tid="44200" TS="0x01D41CD1E34575E5" String1="unable to read configuration file D:\data\yarnnm\logs\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\data\brs\brs.ini" LOG: i,07/15/2018 23:54:48.730,Common,ConfigurationCollection,SrcFile="configurationcollection.cpp" SrcFunc="apsdk::configuration::internal::ConfigurationCollection::Init" SrcLine="110" Pid="63804" Tid="44200" TS="0x01D41CD1E34575E5" String1="unable to read configuration file D:\data\yarnnm\logs\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\data\brs\GlobalBrs.ini" LOG: i,07/15/2018 23:54:48.731,Common,ConfigurationCollection,SrcFile="configurationcollection.cpp" SrcFunc="apsdk::configuration::internal::ConfigurationCollection::Init" SrcLine="110" Pid="63804" Tid="44200" TS="0x01D41CD1E3459CEF" String1="unable to read configuration file D:\data\yarnnm\local\usercache\350a102a-d910-4538-8e7e-4ce6b905fa3f\appcache\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\wd\cosmos.ini.flattened.ini" LOG: w,07/15/2018 23:54:48.731,Common,ConfigurationManager,SrcFile="configurationmanager.cpp" SrcFunc="apsdk::configuration::ConfigurationManager::RegisterBasicConfigurations" SrcLine="383" Pid="63804" Tid="44200" TS="0x01D41CD1E3459CEF" String1="default configuration D:\data\yarnnm\local\usercache\350a102a-d910-4538-8e7e-4ce6b905fa3f\appcache\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\wd\cosmos.ini.flattened.ini not found -- assuming empty" LOG: i,07/15/2018 23:54:48.731,Common,ChangeNotify,SrcFile="changenotify.cpp" SrcFunc="apsdk::ChangeNotifier::Init" SrcLine="71" Pid="63804" Tid="44200" TS="0x01D41CD1E3459CEF" String1="First ChangeNotifier::Init called at 2018-07-15T23:54:48.731L+7h; ScanIntervalMSec=1000, MainLoopSleepIntervalMSec=100" LOG: i,07/15/2018 23:54:48.731,Common,Configuration,SrcFile="configuration.cpp" SrcFunc="apsdk::configuration::Configuration::CompleteInitialize" SrcLine="181" Pid="63804" Tid="44200" TS="0x01D41CD1E3459CEF" String1="Configuration::CompleteInitialize called at 2018-07-15T23:54:48.731L+7h" LOG: i,07/15/2018 23:54:48.731,Common,ConfigurationCollection,SrcFile="configurationcollection.cpp" SrcFunc="apsdk::configuration::internal::ConfigurationCollection::Init" SrcLine="110" Pid="63804" Tid="44200" TS="0x01D41CD1E3459CEF" String1="unable to read configuration file D:\data\yarnnm\logs\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\data\autopilotData\shared.ini" LOG: i,07/15/2018 23:54:48.731,Common,ConfigurationCollection,SrcFile="configurationcollection.cpp" SrcFunc="apsdk::configuration::internal::ConfigurationCollection::Init" SrcLine="110" Pid="63804" Tid="44200" TS="0x01D41CD1E3459CEF" String1="unable to read configuration file D:\data\yarnnm\logs\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\data\autopilotData\Environment.ini" LOG: i,07/15/2018 23:54:48.732,Common,SysInfo::Init,SrcFile="sysinfo.cpp" SrcFunc="apsdk::SysInfo::Init" SrcLine="404" Pid="63804" Tid="44200" TS="0x01D41CD1E345C3CF" String1="Initializing SysInfo at 2018-07-15T23:54:48.732L+7h" LOG: i,07/15/2018 23:54:48.735,Counters,Percentiles,SrcFile="counters.cpp" SrcFunc="apsdk::Counters::ReadTruePercentilesCountersConfiguration" SrcLine="2327" Pid="63804" Tid="44200" TS="0x01D41CD1E3463925" String1="support true percentiles = 0, counters = , counters created = 0" LOG: log4j:WARN No appenders could be found for logger (org.apache.spark.SparkConf). LOG: log4j:WARN Please initialize the log4j system properly. LOG: log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info. LOG: log4j: Reading configuration from URL jar:file:/D:/data/yarnnm/local/usercache/350a102a-d910-4538-8e7e-4ce6b905fa3f/appcache/application_1530846519304_1039/container_e4861_1530846519304_1039_01_000002/wd/archive-java-spark-livy-2.3.0.zip/spark/jars/spark-core_2.11-2.3.0.jar!/org/apache/spark/log4j-defaults.properties LOG: log4j: Parsing for [root] with value=[INFO, console]. LOG: log4j: Level token is [INFO]. LOG: log4j: Category root set to INFO LOG: log4j: Parsing appender named "console". LOG: log4j: Parsing layout options for "console". LOG: log4j: Setting property [conversionPattern] to [%d{yy/MM/dd HH:mm:ss} %p %c{1}: %m%n]. LOG: log4j: End of parsing for "console". LOG: log4j: Setting property [target] to [System.err]. LOG: log4j: Parsed "console" options. LOG: log4j: Parsing for [org.spark_project.jetty] with value=[WARN]. LOG: log4j: Level token is [WARN]. LOG: log4j: Category org.spark_project.jetty set to WARN LOG: log4j: Handling log4j.additivity.org.spark_project.jetty=[null] LOG: log4j: Parsing for [parquet.CorruptStatistics] with value=[ERROR]. LOG: log4j: Level token is [ERROR]. LOG: log4j: Category parquet.CorruptStatistics set to ERROR LOG: log4j: Handling log4j.additivity.parquet.CorruptStatistics=[null] LOG: log4j: Parsing for [org.apache.hadoop.hive.metastore.RetryingHMSHandler] with value=[FATAL]. LOG: log4j: Level token is [FATAL]. LOG: log4j: Category org.apache.hadoop.hive.metastore.RetryingHMSHandler set to FATAL LOG: log4j: Handling log4j.additivity.org.apache.hadoop.hive.metastore.RetryingHMSHandler=[null] LOG: log4j: Parsing for [org.spark_project.jetty.util.component.AbstractLifeCycle] with value=[ERROR]. LOG: log4j: Level token is [ERROR]. LOG: log4j: Category org.spark_project.jetty.util.component.AbstractLifeCycle set to ERROR LOG: log4j: Handling log4j.additivity.org.spark_project.jetty.util.component.AbstractLifeCycle=[null] LOG: log4j: Parsing for [org.apache.spark.repl.SparkILoop$SparkILoopInterpreter] with value=[INFO]. LOG: log4j: Level token is [INFO]. LOG: log4j: Category org.apache.spark.repl.SparkILoop$SparkILoopInterpreter set to INFO LOG: log4j: Handling log4j.additivity.org.apache.spark.repl.SparkILoop$SparkILoopInterpreter=[null] LOG: log4j: Parsing for [org.apache.parquet.CorruptStatistics] with value=[ERROR]. LOG: log4j: Level token is [ERROR]. LOG: log4j: Category org.apache.parquet.CorruptStatistics set to ERROR LOG: log4j: Handling log4j.additivity.org.apache.parquet.CorruptStatistics=[null] LOG: log4j: Parsing for [org.apache.spark.repl.Main] with value=[WARN]. LOG: log4j: Level token is [WARN]. LOG: log4j: Category org.apache.spark.repl.Main set to WARN LOG: log4j: Handling log4j.additivity.org.apache.spark.repl.Main=[null] LOG: log4j: Parsing for [org.apache.spark.repl.SparkIMain$exprTyper] with value=[INFO]. LOG: log4j: Level token is [INFO]. LOG: log4j: Category org.apache.spark.repl.SparkIMain$exprTyper set to INFO LOG: log4j: Handling log4j.additivity.org.apache.spark.repl.SparkIMain$exprTyper=[null] LOG: log4j: Parsing for [org.apache.hadoop.hive.ql.exec.FunctionRegistry] with value=[ERROR]. LOG: log4j: Level token is [ERROR]. LOG: log4j: Category org.apache.hadoop.hive.ql.exec.FunctionRegistry set to ERROR LOG: log4j: Handling log4j.additivity.org.apache.hadoop.hive.ql.exec.FunctionRegistry=[null] LOG: log4j: Finished configuring. LOG: Using Spark's default log4j profile: org/apache/spark/log4j-defaults.properties LOG: 18/07/15 23:54:49 INFO SparkContext: Running Spark version 2.3.0 LOG: 18/07/15 23:54:49 INFO SparkContext: Submitted application: SparkCore_WasbIOTest LOG: 18/07/15 23:54:49 INFO SparkContext: Cosmos environment not set. LOG: 18/07/15 23:54:49 INFO SecurityManager: Changing view acls to: YarnppNMUser LOG: 18/07/15 23:54:49 INFO SecurityManager: Changing modify acls to: YarnppNMUser LOG: at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:151) LOG: at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:112) LOG: at org.apache.spark.rdd.RDD.withScope(RDD.scala:363) LOG: at org.apache.spark.rdd.PairRDDFunctions.saveAsHadoopFile(PairRDDFunctions.scala:957) LOG: at org.apache.spark.rdd.RDD$$anonfun$saveAsTextFile$1.apply$mcV$sp(RDD.scala:1493) LOG: at org.apache.spark.rdd.RDD$$anonfun$saveAsTextFile$1.apply(RDD.scala:1472) LOG: at org.apache.spark.rdd.RDD$$anonfun$saveAsTextFile$1.apply(RDD.scala:1472) LOG: at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:151) LOG: at org.apache.spark.rdd.RDDOperationScope$.withScope(RDDOperationScope.scala:112) LOG: at org.apache.spark.rdd.RDD.withScope(RDD.scala:363) LOG: at org.apache.spark.rdd.RDD.saveAsTextFile(RDD.scala:1472) LOG: at sample.SparkCore_WasbIOTest$.main(SparkCore_WasbIOTest.scala:19) LOG: at sample.SparkCore_WasbIOTest.main(SparkCore_WasbIOTest.scala) LOG: at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) LOG: at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) LOG: at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) LOG: at java.lang.reflect.Method.invoke(Method.java:498) LOG: at org.apache.spark.deploy.JavaMainApplication.start(SparkApplication.scala:52) LOG: at org.apache.spark.deploy.SparkSubmit$.org$apache$spark$deploy$SparkSubmit$$runMain(SparkSubmit.scala:879) LOG: at org.apache.spark.deploy.SparkSubmit$.doRunMain$1(SparkSubmit.scala:197) LOG: at org.apache.spark.deploy.SparkSubmit$.submit(SparkSubmit.scala:227) LOG: at org.apache.spark.deploy.SparkSubmit$.main(SparkSubmit.scala:136) LOG: at org.apache.spark.deploy.SparkSubmit.main(SparkSubmit.scala) LOG: 18/07/15 23:54:51 INFO SparkContext: Invoking stop() from shutdown hook LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,a004500c-c7a3-4cb4-b946-16ba1b3ae2ec: flush called LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,38b526ab-a77d-4493-8ab7-d6c954e4499a: FsWrite starting at 70841 LOG: 18/07/15 23:54:51 INFO SparkUI: Stopped Spark web UI at http://BN4SCH101162724:4040 LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,1034ae4c-955a-4e75-bc57-8d6d5429ff65: doFlush called LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,7395c7f0-b5f0-4d9a-91a1-6c2a9865e955: flush called LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,b6b5c3ab-9c0c-466a-804a-58328350a566: FsWrite starting at 70908 LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,880eb960-05df-4894-ad02-c890ff18eb70: doFlush called LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,2148aa2f-de5e-4ceb-8705-ed43f98d4d8f: flush called LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,47608207-e88c-40f6-a784-03dab7c06c30: FsWrite starting at 70908 LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,f2790ee6-cdc4-4315-bbd3-8c244c3b52b5: doFlush called LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,3815ebc1-b5cb-4a2a-beee-88e0de3fb9f6: close called LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,cb1bf8de-e973-4daa-833a-f770e836298d,d1be0e05-be3d-414c-95b7-8d60e4cd589c: FsWrite starting at 70908 LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,e6ae0899-9202-4635-b2c4-73535ad64230: Cosmos Baseclass getFileStatus got: adl://adlpspark03.caboaccountdogfood.net/spark-events/app-20180715235450-0004 LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,040934dd-a6db-4575-bdcf-b5bdb5ff36c0: ADL doGetFileStatus called with path: adl://adlpspark03.caboaccountdogfood.net/spark-events/app-20180715235450-0004, makeQualified returned: adl://adlpspark03.caboaccountdogfood.net/spark-events/app-20180715235450-0004 LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,77df76b5-9b05-4846-8ba1-62250d5c0ae7: Rename called with src: adl://adlpspark03.caboaccountdogfood.net/spark-events/app-20180715235450-0004.inprogress, dst: adl://adlpspark03.caboaccountdogfood.net/spark-events/app-20180715235450-0004 LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,d5788471-1307-48a7-8b4d-e69bd0dab654: Cosmos Baseclass getFileStatus got: adl://adlpspark03.caboaccountdogfood.net/spark-events/app-20180715235450-0004 LOG: 18/07/15 23:54:51 INFO CosmosFileSystem: Shim=container_e4861_1530846519304_1039_01_000002,a40d8e2b-b4c7-467a-99d9-95ea7b58615f: ADL doGetFileStatus called with path: adl://adlpspark03.caboaccountdogfood.net/spark-events/app-20180715235450-0004, makeQualified returned: adl://adlpspark03.caboaccountdogfood.net/spark-events/app-20180715235450-0004 LOG: 18/07/15 23:54:51 INFO StandaloneAppClient$ClientEndpoint: Executor updated: app-20180715235450-0004/19 is now RUNNING LOG: 18/07/15 23:54:51 INFO StandaloneSchedulerBackend: Shutting down all executors LOG: 18/07/15 23:54:51 INFO CoarseGrainedSchedulerBackend$DriverEndpoint: Asking each executor to shut down LOG: 18/07/15 23:54:51 INFO MapOutputTrackerMasterEndpoint: MapOutputTrackerMasterEndpoint stopped! LOG: 18/07/15 23:54:51 INFO MemoryStore: MemoryStore cleared LOG: 18/07/15 23:54:51 INFO BlockManager: BlockManager stopped LOG: 18/07/15 23:54:51 INFO BlockManagerMaster: BlockManagerMaster stopped LOG: 18/07/15 23:54:51 INFO OutputCommitCoordinator$OutputCommitCoordinatorEndpoint: OutputCommitCoordinator stopped! LOG: 18/07/15 23:54:51 INFO SparkContext: Successfully stopped SparkContext LOG: 18/07/15 23:54:51 INFO ShutdownHookManager: Shutdown hook called LOG: 18/07/15 23:54:51 INFO ShutdownHookManager: Deleting directory D:\data\yarnnm\local\usercache\350a102a-d910-4538-8e7e-4ce6b905fa3f\appcache\application_1530846519304_1039\spark-1237e085-5529-4e8b-a52f-d69f601ae51d LOG: 18/07/15 23:54:51 INFO ShutdownHookManager: Deleting directory D:\data\yarnnm\local\usercache\350a102a-d910-4538-8e7e-4ce6b905fa3f\appcache\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\wd\spark-2e41222d-37dd-4eee-a9f6-a242fbed4939 LOG: 18/07/15 23:54:51 ERROR ShutdownHookManager: Exception while deleting Spark temp dir: D:\data\yarnnm\local\usercache\350a102a-d910-4538-8e7e-4ce6b905fa3f\appcache\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\wd\spark-2e41222d-37dd-4eee-a9f6-a242fbed4939 LOG: java.io.IOException: Failed to delete: D:\data\yarnnm\local\usercache\350a102a-d910-4538-8e7e-4ce6b905fa3f\appcache\application_1530846519304_1039\container_e4861_1530846519304_1039_01_000002\wd\spark-2e41222d-37dd-4eee-a9f6-a242fbed4939 LOG: at org.apache.spark.util.Utils$.deleteRecursively(Utils.scala:1070) LOG: at org.apache.spark.util.ShutdownHookManager$$anonfun$1$$anonfun$apply$mcV$sp$3.apply(ShutdownHookManager.scala:65) LOG: at org.apache.spark.util.ShutdownHookManager$$anonfun$1$$anonfun$apply$mcV$sp$3.apply(ShutdownHookManager.scala:62) LOG: at scala.collection.IndexedSeqOptimized$class.foreach(IndexedSeqOptimized.scala:33) LOG: at scala.collection.mutable.ArrayOps$ofRef.foreach(ArrayOps.scala:186) LOG: at org.apache.spark.util.ShutdownHookManager$$anonfun$1.apply$mcV$sp(ShutdownHookManager.scala:62) LOG: at org.apache.spark.util.SparkShutdownHook.run(ShutdownHookManager.scala:216) LOG: at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1$$anonfun$apply$mcV$sp$1.apply$mcV$sp(ShutdownHookManager.scala:188) LOG: at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1$$anonfun$apply$mcV$sp$1.apply(ShutdownHookManager.scala:188) LOG: at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1$$anonfun$apply$mcV$sp$1.apply(ShutdownHookManager.scala:188) LOG: at org.apache.spark.util.Utils$.logUncaughtExceptions(Utils.scala:1988) LOG: at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply$mcV$sp(ShutdownHookManager.scala:188) LOG: at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply(ShutdownHookManager.scala:188) LOG: at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply(ShutdownHookManager.scala:188) LOG: at scala.util.Try$.apply(Try.scala:192) LOG: at org.apache.spark.util.SparkShutdownHookManager.runAll(ShutdownHookManager.scala:188) LOG: at org.apache.spark.util.SparkShutdownHookManager$$anon$2.run(ShutdownHookManager.scala:178) LOG: at org.apache.hadoop.util.ShutdownHookManager$1.run(ShutdownHookManager.java:54) ERROR: The Spark job failed to start due to at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1$$anonfun$apply$mcV$sp$1.apply(ShutdownHookManager.scala:188) at org.apache.spark.util.Utils$.logUncaughtExceptions(Utils.scala:1988) at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply$mcV$sp(ShutdownHookManager.scala:188) at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply(ShutdownHookManager.scala:188) at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply(ShutdownHookManager.scala:188) at scala.util.Try$.apply(Try.scala:192) at org.apache.spark.util.SparkShutdownHookManager.runAll(ShutdownHookManager.scala:188) at org.apache.spark.util.SparkShutdownHookManager$$anon$2.run(ShutdownHookManager.scala:178) at org.apache.hadoop.util.ShutdownHookManager$1.run(ShutdownHookManager.java:54)

stderr: stack trace: com.microsoft.azure.hdinsight.spark.common.SparkJobException: The Spark job failed to start due to at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1$$anonfun$apply$mcV$sp$1.apply(ShutdownHookManager.scala:188) at org.apache.spark.util.Utils$.logUncaughtExceptions(Utils.scala:1988) at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply$mcV$sp(ShutdownHookManager.scala:188) at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply(ShutdownHookManager.scala:188) at org.apache.spark.util.SparkShutdownHookManager$$anonfun$runAll$1.apply(ShutdownHookManager.scala:188) at scala.util.Try$.apply(Try.scala:192) at org.apache.spark.util.SparkShutdownHookManager.runAll(ShutdownHookManager.scala:188) at org.apache.spark.util.SparkShutdownHookManager$$anon$2.run(ShutdownHookManager.scala:178) at org.apache.hadoop.util.ShutdownHookManager$1.run(ShutdownHookManager.java:54)

stderr: at com.microsoft.azure.hdinsight.spark.common.SparkBatchJob.lambda$awaitStarted$49(SparkBatchJob.java:1125) at rx.internal.operators.OnSubscribeMap$MapSubscriber.onNext(OnSubscribeMap.java:69) at rx.internal.operators.OnSubscribeFilter$FilterSubscriber.onNext(OnSubscribeFilter.java:76) at rx.internal.operators.OperatorTakeUntilPredicate$ParentSubscriber.onNext(OperatorTakeUntilPredicate.java:61) at rx.internal.operators.OnSubscribeRedo$2$1.onNext(OnSubscribeRedo.java:244) at rx.internal.operators.OnSubscribeRedo$2$1.onNext(OnSubscribeRedo.java:244) at rx.internal.operators.OnSubscribeMap$MapSubscriber.onNext(OnSubscribeMap.java:77) at rx.internal.producers.SingleDelayedProducer.emit(SingleDelayedProducer.java:102) at rx.internal.producers.SingleDelayedProducer.setValue(SingleDelayedProducer.java:85) at rx.internal.operators.OnSubscribeFromCallable.call(OnSubscribeFromCallable.java:48) at rx.internal.operators.OnSubscribeFromCallable.call(OnSubscribeFromCallable.java:33) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeRedo$2.call(OnSubscribeRedo.java:273) at rx.internal.schedulers.TrampolineScheduler$InnerCurrentThreadScheduler.enqueue(TrampolineScheduler.java:73) at rx.internal.schedulers.TrampolineScheduler$InnerCurrentThreadScheduler.schedule(TrampolineScheduler.java:52) at rx.internal.operators.OnSubscribeRedo$5.request(OnSubscribeRedo.java:361) at rx.internal.producers.ProducerArbiter.setProducer(ProducerArbiter.java:126) at rx.internal.operators.OnSubscribeRedo$2$1.setProducer(OnSubscribeRedo.java:267) at rx.internal.operators.OnSubscribeRedo.call(OnSubscribeRedo.java:353) at rx.internal.operators.OnSubscribeRedo.call(OnSubscribeRedo.java:47) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeRedo$2.call(OnSubscribeRedo.java:273) at rx.internal.schedulers.TrampolineScheduler$InnerCurrentThreadScheduler.enqueue(TrampolineScheduler.java:73) at rx.internal.schedulers.TrampolineScheduler$InnerCurrentThreadScheduler.schedule(TrampolineScheduler.java:52) at rx.internal.operators.OnSubscribeRedo$5.request(OnSubscribeRedo.java:361) at rx.Subscriber.setProducer(Subscriber.java:211) at rx.internal.operators.OnSubscribeRedo.call(OnSubscribeRedo.java:353) at rx.internal.operators.OnSubscribeRedo.call(OnSubscribeRedo.java:47) at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48) at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeFilter.call(OnSubscribeFilter.java:45) at rx.internal.operators.OnSubscribeFilter.call(OnSubscribeFilter.java:30) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33) at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48) at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33) at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48) at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:248) at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:148) at rx.internal.operators.OnSubscribeMap$MapSubscriber.onNext(OnSubscribeMap.java:77) at rx.internal.operators.OperatorMerge$MergeSubscriber.emitScalar(OperatorMerge.java:395) at rx.internal.operators.OperatorMerge$MergeSubscriber.tryEmit(OperatorMerge.java:355) at rx.internal.operators.OperatorMerge$InnerSubscriber.onNext(OperatorMerge.java:846) at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onNext(OnSubscribeDoOnEach.java:101) at rx.internal.operators.OperatorMerge$MergeSubscriber.emitScalar(OperatorMerge.java:395) at rx.internal.operators.OperatorMerge$MergeSubscriber.tryEmit(OperatorMerge.java:355) at rx.internal.operators.OperatorMerge$InnerSubscriber.onNext(OperatorMerge.java:846) at rx.internal.operators.OnSubscribeMap$MapSubscriber.onNext(OnSubscribeMap.java:77) at rx.internal.producers.SingleProducer.request(SingleProducer.java:65) at rx.Subscriber.setProducer(Subscriber.java:211) at rx.internal.operators.OnSubscribeMap$MapSubscriber.setProducer(OnSubscribeMap.java:102) at rx.internal.operators.OperatorSingle$ParentSubscriber.onCompleted(OperatorSingle.java:110) at rx.internal.operators.DeferredScalarSubscriber.complete(DeferredScalarSubscriber.java:102) at rx.internal.operators.OnSubscribeTakeLastOne$TakeLastOneSubscriber.onCompleted(OnSubscribeTakeLastOne.java:57) at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onCompleted(OnSubscribeDoOnEach.java:70) at rx.internal.operators.OnSubscribeDoOnEach$DoOnEachSubscriber.onCompleted(OnSubscribeDoOnEach.java:70) at com.microsoft.azure.hdinsight.spark.common.SparkBatchJob.lambda$getSubmissionLog$29(SparkBatchJob.java:817) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:41) at rx.internal.operators.OnSubscribeDoOnEach.call(OnSubscribeDoOnEach.java:30) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.DeferredScalarSubscriber.subscribeTo(DeferredScalarSubscriber.java:153) at rx.internal.operators.OnSubscribeTakeLastOne.call(OnSubscribeTakeLastOne.java:32) at rx.internal.operators.OnSubscribeTakeLastOne.call(OnSubscribeTakeLastOne.java:22) at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:48) at rx.internal.operators.OnSubscribeLift.call(OnSubscribeLift.java:30) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:48) at rx.internal.operators.OnSubscribeMap.call(OnSubscribeMap.java:33) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:248) at rx.internal.operators.OperatorMerge$MergeSubscriber.onNext(OperatorMerge.java:148) at rx.internal.operators.OnSubscribeMap$MapSubscriber.onNext(OnSubscribeMap.java:77) at rx.internal.operators.OperatorSubscribeOn$1$1.onNext(OperatorSubscribeOn.java:53) at rx.internal.producers.SingleDelayedProducer.emit(SingleDelayedProducer.java:102) at rx.internal.producers.SingleDelayedProducer.setValue(SingleDelayedProducer.java:85) at rx.internal.operators.OnSubscribeFromCallable.call(OnSubscribeFromCallable.java:48) at rx.internal.operators.OnSubscribeFromCallable.call(OnSubscribeFromCallable.java:33) at rx.Observable.unsafeSubscribe(Observable.java:10142) at rx.internal.operators.OperatorSubscribeOn$1.call(OperatorSubscribeOn.java:94) at rx.internal.schedulers.ScheduledAction.run(ScheduledAction.java:55) at rx.internal.schedulers.ExecutorScheduler$ExecutorSchedulerWorker.run(ExecutorScheduler.java:107) at com.microsoft.intellij.rxjava.IdeaSchedulers$1.run(IdeaSchedulers.java:53) at com.intellij.openapi.progress.impl.CoreProgressManager$TaskRunnable.run(CoreProgressManager.java:750) at com.intellij.openapi.progress.impl.CoreProgressManager.lambda$runProcess$1(CoreProgressManager.java:157) at com.intellij.openapi.progress.impl.CoreProgressManager.registerIndicatorAndRun(CoreProgressManager.java:580) at com.intellij.openapi.progress.impl.CoreProgressManager.executeProcessUnderProgress(CoreProgressManager.java:525) at com.intellij.openapi.progress.impl.ProgressManagerImpl.executeProcessUnderProgress(ProgressManagerImpl.java:85) at com.intellij.openapi.progress.impl.CoreProgressManager.runProcess(CoreProgressManager.java:144) at com.intellij.openapi.progress.impl.CoreProgressManager$4.run(CoreProgressManager.java:395) at com.intellij.openapi.application.impl.ApplicationImpl$1.run(ApplicationImpl.java:305) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) 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)

wezhang commented 6 years ago

Backend issue.