Problem with Spark + Ozone

[yazynin]

We're using Ozone 1.4.0 + Spark 3.2.3, periodically applications crashed with errors:

2024-04-26 11:53:23,968 INFO scheduler.TaskSetManager: Starting task 7.2 in stage 221.0 (TID 263) (prod-ozone-datanode009.acme.com, executor 2, partition 7, PROCESS_LOCAL, 4431 bytes) taskResourceAssignments Map()
2024-04-26 11:53:23,970 WARN scheduler.TaskSetManager: Lost task 19.1 in stage 221.0 (TID 257) (prod-ozone-datanode009.acme.com executor 2): org.apache.hadoop.ipc.RemoteException(org.apache.hadoop.ozone.om.exceptions.OMNotLeaderException): OM:om2 is not the leader. Suggested leader is OM:om1[prod-ozone-master004.acme.com/172.16.6.9].
	at org.apache.hadoop.ipc.Client.getRpcResponse(Client.java:1612)
	at org.apache.hadoop.ipc.Client.call(Client.java:1558)
	at org.apache.hadoop.ipc.Client.call(Client.java:1455)
	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:235)
	at org.apache.hadoop.ipc.ProtobufRpcEngine$Invoker.invoke(ProtobufRpcEngine.java:122)
	at com.sun.proxy.$Proxy21.submitRequest(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.hadoop.io.retry.RetryInvocationHandler.invokeMethod(RetryInvocationHandler.java:422)
	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeMethod(RetryInvocationHandler.java:165)
	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invoke(RetryInvocationHandler.java:157)
	at org.apache.hadoop.io.retry.RetryInvocationHandler$Call.invokeOnce(RetryInvocationHandler.java:95)
	at org.apache.hadoop.io.retry.RetryInvocationHandler.invoke(RetryInvocationHandler.java:359)
	at com.sun.proxy.$Proxy21.submitRequest(Unknown Source)
	at org.apache.hadoop.ozone.om.protocolPB.Hadoop3OmTransport.submitRequest(Hadoop3OmTransport.java:80)
	at org.apache.hadoop.ozone.om.protocolPB.OzoneManagerProtocolClientSideTranslatorPB.submitRequest(OzoneManagerProtocolClientSideTranslatorPB.java:330)
	at org.apache.hadoop.ozone.om.protocolPB.OzoneManagerProtocolClientSideTranslatorPB.getKeyInfo(OzoneManagerProtocolClientSideTranslatorPB.java:864)
	at org.apache.hadoop.ozone.client.rpc.RpcClient.readFile(RpcClient.java:2001)
	at org.apache.hadoop.ozone.client.OzoneBucket.readFile(OzoneBucket.java:805)
	at org.apache.hadoop.fs.ozone.BasicRootedOzoneClientAdapterImpl.readFile(BasicRootedOzoneClientAdapterImpl.java:359)
	at org.apache.hadoop.fs.ozone.BasicRootedOzoneFileSystem.open(BasicRootedOzoneFileSystem.java:242)
	at org.apache.hadoop.fs.FileSystem.open(FileSystem.java:976)
	at com.uzumdata.ml.core.storage.batch.BatchBoundsStorageClient.readJsonFile(BatchBoundsStorageClient.scala:102)
	at com.uzumdata.ml.core.storage.batch.BatchBoundsStorageClient.read(BatchBoundsStorageClient.scala:40)
	at com.uzumdata.ml.core.transformers.features.percentiles.PercentilesTransformer.featuresPrepared$1(PercentilesTransformer.scala:98)
	at com.uzumdata.ml.core.transformers.features.percentiles.PercentilesTransformer.$anonfun$transform$10(PercentilesTransformer.scala:141)
	at scala.collection.Iterator$$anon$10.next(Iterator.scala:461)
	at scala.collection.Iterator$$anon$10.next(Iterator.scala:461)
	at scala.collection.Iterator$$anon$10.next(Iterator.scala:461)
	at org.apache.spark.sql.execution.aggregate.TungstenAggregationIterator.processInputs(TungstenAggregationIterator.scala:193)
	at org.apache.spark.sql.execution.aggregate.TungstenAggregationIterator.<init>(TungstenAggregationIterator.scala:364)
	at org.apache.spark.sql.execution.aggregate.HashAggregateExec.$anonfun$doExecute$1(HashAggregateExec.scala:122)
	at org.apache.spark.sql.execution.aggregate.HashAggregateExec.$anonfun$doExecute$1$adapted(HashAggregateExec.scala:96)
	at org.apache.spark.rdd.RDD.$anonfun$mapPartitionsWithIndex$2(RDD.scala:915)
	at org.apache.spark.rdd.RDD.$anonfun$mapPartitionsWithIndex$2$adapted(RDD.scala:915)
	at org.apache.spark.rdd.MapPartitionsRDD.compute(MapPartitionsRDD.scala:52)
	at org.apache.spark.rdd.RDD.computeOrReadCheckpoint(RDD.scala:373)
	at org.apache.spark.rdd.RDD.iterator(RDD.scala:337)
	at org.apache.spark.rdd.MapPartitionsRDD.compute(MapPartitionsRDD.scala:52)
	at org.apache.spark.rdd.RDD.computeOrReadCheckpoint(RDD.scala:373)
	at org.apache.spark.rdd.RDD.iterator(RDD.scala:337)
	at org.apache.spark.shuffle.ShuffleWriteProcessor.write(ShuffleWriteProcessor.scala:59)
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:99)
	at org.apache.spark.scheduler.ShuffleMapTask.runTask(ShuffleMapTask.scala:52)
	at org.apache.spark.scheduler.Task.run(Task.scala:131)
	at org.apache.spark.executor.Executor$TaskRunner.$anonfun$run$3(Executor.scala:506)
	at org.apache.spark.util.Utils$.tryWithSafeFinally(Utils.scala:1491)
	at org.apache.spark.executor.Executor$TaskRunner.run(Executor.scala:509)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:750)

in nodemanager log

at org.apache.hadoop.ozone.protocolPB.OzoneManagerProtocolServerSideTranslatorPB.createLeaderErrorException(OzoneManagerProtocolServerSideTranslatorPB.java:273)
	at org.apache.hadoop.ozone.protocolPB.OzoneManagerProtocolServerSideTranslatorPB.createLeaderErrorException(OzoneManagerProtocolServerSideTranslatorPB.java:273)
2024-04-26 13:22:27,286 ERROR org.apache.hadoop.ozone.om.ha.OMFailoverProxyProviderBase: Failed to connect to OMs: [om1, om2, om3]. Attempted 500 failovers.
2024-04-26 13:22:27,287 ERROR org.apache.hadoop.yarn.server.nodemanager.containermanager.localizer.ResourceLocalizationService: Failed to download resource { { ofs://cluster1/user/acme/.sparkStaging/application_1713388773506_5357/__spark_conf__.zip, 1714136303487, ARCHIVE, null },pending,[(container_e46_1713388773506_5357_01_000001)],101872570839703,DOWNLOADING} org.apache.hadoop.yarn.exceptions.YarnException: Download and unpack failed
	at org.apache.hadoop.ozone.protocolPB.OzoneManagerProtocolServerSideTranslatorPB.createLeaderErrorException(OzoneManagerProtocolServerSideTranslatorPB.java:273)
2024-04-26 13:22:29,491 ERROR org.apache.hadoop.ozone.client.OzoneClientFactory: Couldn't create RpcClient protocol exception:

in om logs:

2024-04-26 12:41:24,692 WARN org.apache.hadoop.ipc.Server: IPC Server handler 52 on default port 9862, call Call#1001930 Retry#489 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:35987 / 172.16.6.28:35987
2024-04-26 12:41:26,697 WARN org.apache.hadoop.ipc.Server: IPC Server handler 93 on default port 9862, call Call#1001930 Retry#492 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:35987 / 172.16.6.28:35987
2024-04-26 12:41:28,708 WARN org.apache.hadoop.ipc.Server: IPC Server handler 91 on default port 9862, call Call#1001930 Retry#495 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:35987 / 172.16.6.28:35987
2024-04-26 12:41:30,713 WARN org.apache.hadoop.ipc.Server: IPC Server handler 83 on default port 9862, call Call#1001930 Retry#498 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:35987 / 172.16.6.28:35987
2024-04-26 12:41:30,838 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for acme@acme.COM (auth:TOKEN) from prod-ozone-datanode009.acme.com:42822 / 172.16.6.28:42822
2024-04-26 12:41:30,907 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for acme@acme.COM (auth:TOKEN) from prod-ozone-datanode009.acme.com:42834 / 172.16.6.28:42834
2024-04-26 12:42:18,608 INFO org.apache.hadoop.hdds.utils.BackgroundService: Send 1 key(s) to SCM, first 1 keys: [BlockGroup[groupID='/yarn/yarn-apps-logs/acme/bucket-logs-tfile/5339/application_1713388773506_5339/prod-ozone-datanode009.acme.com_37899.tmp/-9223372031036565247', blockIDs=[conID: 11069 locID: 111677748023114868 bcsId: 0]]]
2024-04-26 12:43:18,608 INFO org.apache.hadoop.hdds.utils.BackgroundService: Send 4 key(s) to SCM, first 4 keys: [BlockGroup[groupID='/user/acme/.sparkStaging/application_1713388773506_5339/__spark_conf__.zip/-9223372031036787967', blockIDs=[conID: 11066 locID: 111677748023114776 bcsId: 0]], BlockGroup[groupID='/yarn/yarn-apps-logs/fgAWWmMo.permission_check/-9223372031036549376', blockIDs=[conID: 11053 locID: 111677748023114874 bcsId: 0]], BlockGroup[groupID='/yarn/yarn-apps-logs/kbe0mZcp.permission_check/-9223372031036545792', blockIDs=[conID: 11045 locID: 111677748023114876 bcsId: 0]], BlockGroup[groupID='/yarn/yarn-apps-logs/acme/bucket-logs-tfile/5339/application_1713388773506_5339/prod-ozone-datanode009.acme.com_37899.tmp/-9223372031036565247', blockIDs=[conID: 11069 locID: 111677748023114868 bcsId: 0]]]
2024-04-26 12:44:18,608 INFO org.apache.hadoop.hdds.utils.BackgroundService: Send 8 key(s) to SCM, first 8 keys: [BlockGroup[groupID='/data/acme/_SUCCESS/-9223372031036540672', blockIDs=[conID: 11068 locID: 111677748023114878 bcsId: 0]], BlockGroup[groupID='/temp/qa-data/qatest/.sparkStaging/application_1713388773506_5347/__spark_conf__.zip/-9223372031036590847', blockIDs=[conID: 11053 locID: 111677748023114858 bcsId: 0]], BlockGroup[groupID='/user/acme/.sparkStaging/application_1713388773506_5339/__spark_conf__.zip/-9223372031036787967', blockIDs=[conID: 11066 locID: 111677748023114776 bcsId: 0]], BlockGroup[groupID='/yarn/yarn-apps-logs/fgAWWmMo.permission_check/-9223372031036549376', blockIDs=[conID: 11053 locID: 111677748023114874 bcsId: 0]], BlockGroup[groupID='/yarn/yarn-apps-logs/kbe0mZcp.permission_check/-9223372031036545792', blockIDs=[conID: 11045 locID: 111677748023114876 bcsId: 0]], BlockGroup[groupID='/yarn/yarn-apps-logs/acme/bucket-logs-tfile/5339/application_1713388773506_5339/prod-ozone-datanode009.acme.com_37899.tmp/-9223372031036565247', blockIDs=[conID: 11069 locID: 111677748023114868 bcsId: 0]], BlockGroup[groupID='/yarn/yarn-apps-logs/nwTp8K1j.permission_check/-9223372031036530432', blockIDs=[conID: 11037 locID: 111677748023114884 bcsId: 0]], BlockGroup[groupID='/yarn/yarn-apps-logs/yVRoIvqK.permission_check/-9223372031036536064', blockIDs=[conID: 11063 locID: 111677748023114880 bcsId: 0]]]
2024-04-26 12:49:28,699 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for YARN/prod-ozone-datanode009.acme.com@acme.COM (auth:KERBEROS) from prod-ozone-datanode009.acme.com:40475 / 172.16.6.28:40475
2024-04-26 12:49:28,702 INFO SecurityLogger.org.apache.hadoop.security.authorize.ServiceAuthorizationManager: Authorization successful for YARN/prod-ozone-datanode009.acme.com@acme.COM (auth:KERBEROS) for protocol=interface org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol
2024-04-26 12:49:28,751 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for acme@acme.COM (auth:TOKEN) from prod-ozone-datanode009.acme.com:52706 / 172.16.6.28:52706
2024-04-26 12:49:32,078 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for acme@acme.COM (auth:TOKEN) from prod-ozone-datanode009.acme.com:52708 / 172.16.6.28:52708
2024-04-26 12:49:54,321 INFO SecurityLogger.org.apache.hadoop.ipc.Server: Auth successful for acme@acme.COM (auth:TOKEN) from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:49:54,971 WARN org.apache.hadoop.ipc.Server: IPC Server handler 10 on default port 9862, call Call#49 Retry#0 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:49:56,992 WARN org.apache.hadoop.ipc.Server: IPC Server handler 77 on default port 9862, call Call#49 Retry#3 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:49:59,008 WARN org.apache.hadoop.ipc.Server: IPC Server handler 28 on default port 9862, call Call#49 Retry#6 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:50:01,022 WARN org.apache.hadoop.ipc.Server: IPC Server handler 92 on default port 9862, call Call#49 Retry#9 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:50:03,032 WARN org.apache.hadoop.ipc.Server: IPC Server handler 55 on default port 9862, call Call#49 Retry#12 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:50:05,042 WARN org.apache.hadoop.ipc.Server: IPC Server handler 39 on default port 9862, call Call#49 Retry#15 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:50:07,057 WARN org.apache.hadoop.ipc.Server: IPC Server handler 26 on default port 9862, call Call#49 Retry#18 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:50:09,069 WARN org.apache.hadoop.ipc.Server: IPC Server handler 72 on default port 9862, call Call#49 Retry#21 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:50:11,079 WARN org.apache.hadoop.ipc.Server: IPC Server handler 52 on default port 9862, call Call#49 Retry#24 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:50:13,092 WARN org.apache.hadoop.ipc.Server: IPC Server handler 91 on default port 9862, call Call#49 Retry#27 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:50:15,104 WARN org.apache.hadoop.ipc.Server: IPC Server handler 41 on default port 9862, call Call#49 Retry#30 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506
2024-04-26 12:50:17,115 WARN org.apache.hadoop.ipc.Server: IPC Server handler 59 on default port 9862, call Call#49 Retry#33 org.apache.hadoop.ozone.om.protocol.OzoneManagerProtocol.submitRequest from prod-ozone-datanode009.acme.com:38506 / 172.16.6.28:38506

How can it be fixed, how else can the logs be viewed?

[smengcl]

Hi @yazynin , it looks like a connectivity issue:

2024-04-26 13:22:27,286 ERROR org.apache.hadoop.ozone.om.ha.OMFailoverProxyProviderBase: Failed to connect to OMs: [om1, om2, om3]. Attempted 500 failovers.

Are you able to run some basic Ozone CLI commands from the node where Spark is running on? Just to confirm if that node can connect to the OM.

[yazynin]

At same time ozone worked correct for another files, looks like problem only with reading and writing "sparkStaging" files: for example "Failed to download resource { { ofs://cluster1/user/acme/.sparkStaging/application_1713388773506_5357/__spark_conf__.zip, 1714136303487, ARCHIVE, null },"