Spark-on-k8s-operator: Job never comes up and fails with driver pod not found
Sometimes the creation request succeeds and then the job never comes up and doing a describe on the spark application shows
SparkApplicationFailed 6m54s spark-operator SparkApplication log-validation failed: Driver Pod not found
We've seen this happen about 25% of the time. Any advice ?
sb2nov
All 38 comments
Which version of the operator are you running? This kind of error happens typically because the controller reconciliation logic tries to get the driver pod and fails to find it in the cache (the local client informer cache that is asynchronously synced against the API server). We have made changes to fallback to get the driver pod directly from the k8s API server if it is not found in the cache.
liyinan926
on 7 Feb 2020
I'm running the 2.4.4 version
sb2nov
on 7 Feb 2020
What is the image tag of the version you are running?
liyinan926
on 8 Feb 2020
Image: gcr.io/spark-operator/spark-operator:v1beta2-1.0.1-2.4.4
Image ID: docker-pullable://gcr.io/spark-operator/spark-operator@sha256:ce769e5c6a5d8fa78ceb1a0abaf961fb2424767f9535c97baac04a18169654bd
sb2nov
on 8 Feb 2020
Please give the new release based on 2.4.5 a try and let me know if you still run into the same issue.
liyinan926
on 10 Feb 2020
Still seeing the same issue.
Type Reason Age From Message
---- ------ ---- ---- -------
Normal SparkApplicationAdded 58s spark-operator SparkApplication logs-batch was added, enqueuing it for submission
Normal SparkApplicationSubmitted 53s spark-operator SparkApplication logs-batch was submitted successfully
Normal SparkApplicationSpecUpdateProcessed 53s spark-operator Successfully processed spec update for SparkApplication logs-batch
Warning SparkApplicationFailed 52s spark-operator SparkApplication logs-batch failed: Driver Pod not found
I have exactly the same issue.
julio666
on 11 Feb 2020
@sb2nov I saw a SparkApplicationSpecUpdateProcessed event on your SparkApplication resource. Did you make an update to the spec after submission?
liyinan926
on 11 Feb 2020
I did not change that. It was just one kubectl apply. I'm using the operator installed by helm.
sb2nov
on 11 Feb 2020
Did you enable Prometheus monitoring? Can you paste your SparkApplication spec here?
liyinan926
on 11 Feb 2020
I do have prometheus monitoring turned on:
Name: logs-batch
Namespace: sourabh
Labels: <none>
Annotations: kubectl.kubernetes.io/last-applied-configuration:
{"apiVersion":"sparkoperator.k8s.io/v1beta2","kind":"SparkApplication","metadata":{"annotations":{},"name":"logs-batch","namespace...
API Version: sparkoperator.k8s.io/v1beta2
Kind: SparkApplication
Metadata:
Creation Timestamp: 2020-02-11T22:33:00Z
Generation: 1
Resource Version: 46870186
Self Link: /apis/sparkoperator.k8s.io/v1beta2/namespaces/sourabh/sparkapplications/logs-batch
UID: 7576d9e5-4d1e-11ea-8be9-02f34443fbf2
Spec:
Driver:
Cores: 1
Env Vars:
INDEX LOG KAFKA: log-events
KAFKA BROKERS: pubsub-0.pubsub:9092,pubsub-1.pubsub:9092,pubsub-2.pubsub:9092
SCHEMA REGISTRY: http://cp-schema-registry:8081
ZOOKEEPER: zookeeper:2181
Memory: 1024m
Service Account: spark
Executor:
Cores: 1
Instances: 3
Memory: 2048m
Hadoop Conf:
Fs . S 3 A . Aws . Credentials . Provider: com.amazonaws.auth.InstanceProfileCredentialsProvider
Fs . S 3 A . Impl: org.apache.hadoop.fs.s3a.S3AFileSystem
Fs . S 3 A . Path . Style . Access: true
Validate Output Specs: false
Image: scratchspace:sourabh-20200211143232-dev
Image Pull Policy: Always
Main Application File: local:///opt/spark/work-dir/logs_batch.py
Mode: cluster
Monitoring:
Expose Driver Metrics: true
Expose Executor Metrics: true
Prometheus:
Jmx Exporter Jar: /opt/spark/jars/jmx_prometheus_javaagent-0.11.0.jar
Python Version: 3
Restart Policy:
On Submission Failure Retries: 5
On Submission Failure Retry Interval: 20
Type: OnFailure
Spark Conf:
Spark . Kubernetes . Local . Dirs . Tmpfs: true
Spark . Kubernetes . Namespace: sourabh
Spark Version: 2.4.4
Type: Python
Status:
Application State:
Error Message: Driver Pod not found
State: FAILED
Driver Info:
Pod Name: logs-batch-driver
Web UI Address: 10.100.18.81:4040
Web UI Port: 4040
Web UI Service Name: logs-batch-ui-svc
Execution Attempts: 1
Last Submission Attempt Time: 2020-02-11T22:33:05Z
Spark Application Id: spark-0e3107d4b23f4387b93802d14939fdf4
Submission Attempts: 1
Submission ID: 16c9b013-ec77-493c-ab03-d492735a37d0
Termination Time: 2020-02-11T22:33:05Z
Events:
Type Reason Age From Message
---- ------ ---- ---- -------
Normal SparkApplicationAdded 43s spark-operator SparkApplication logs-batch was added, enqueuing it for submission
Normal SparkApplicationSubmitted 38s spark-operator SparkApplication logs-batch was submitted successfully
Normal SparkApplicationSpecUpdateProcessed 38s spark-operator Successfully processed spec update for SparkApplication logs-batch
Warning SparkApplicationFailed 37s (x2 over 38s) spark-operator SparkApplication logs-batch failed: Driver Pod not found
Removing everything below Monitoring: does make it a lot more stable in the 10 runs I did.
sb2nov
on 12 Feb 2020
That explains it. Enabling Prometheus monitoring will modify the spec with some additional annotations, which causes the submitted run to be invalidated and the driver pod to get deleted. There's a bug here: we should not write the updated spec to the API server as we only use it to construct the submission command. Will fix that.
liyinan926
on 12 Feb 2020
Thank you for the help.
sb2nov
on 12 Feb 2020
Created https://github.com/GoogleCloudPlatform/spark-on-k8s-operator/pull/804 to fix the unwanted spec update. Will include it in the latest release image, and will make a new bug fix release later.
liyinan926
on 12 Feb 2020
Awesome. Thank you so much, really appreciate the help.
sb2nov
on 12 Feb 2020
The spec update issue has been fixed and the image has been updated. Please uninstall and reinstall through Helm.
liyinan926
on 12 Feb 2020
@liyinan926 I'm still seeing the issue. The operator is running image:
Image: gcr.io/spark-operator/spark-operator:v1beta2-1.1.0-2.4.5
Image ID: docker-pullable://gcr.io/spark-operator/spark-operator@sha256:c59931eb2fcbcd51750fa70d253ed445dfa5f7b8d1e6594550310a02b18ce5f9
Are you still seeing the event SparkApplicationSpecUpdateProcessed? Can you do a kubectl get sparkapplication <name> -o=yaml after the error was reported?
liyinan926
on 12 Feb 2020
Yes, still seeing the UpdateProcessed.
apiVersion: sparkoperator.k8s.io/v1beta2
kind: SparkApplication
metadata:
annotations:
kubectl.kubernetes.io/last-applied-configuration: |
{"apiVersion":"sparkoperator.k8s.io/v1beta2","kind":"SparkApplication","metadata":{"annotations":{},***********}
creationTimestamp: "2020-02-12T02:10:26Z"
generation: 1
name: logs-batch
namespace: sourabh
resourceVersion: "46990703"
selfLink: /apis/sparkoperator.k8s.io/v1beta2/namespaces/sourabh/sparkapplications/logs-batch
uid: d5c7954b-4d3c-11ea-bcb5-06d1592d959c
spec:
driver:
cores: 1
envVars:
SCHEMA_REGISTRY: http://cp-schema-registry:8081
ZOOKEEPER: zookeeper:2181
memory: 1024m
serviceAccount: spark
executor:
cores: 1
instances: 3
memory: 2048m
hadoopConf:
fs.s3a.aws.credentials.provider: com.amazonaws.auth.InstanceProfileCredentialsProvider
fs.s3a.impl: org.apache.hadoop.fs.s3a.S3AFileSystem
fs.s3a.path.style.access: "true"
validateOutputSpecs: "false"
image: scratchspace:sourabhbajaj-20200211181007-dev
imagePullPolicy: Always
mainApplicationFile: local:///opt/spark/work-dir/logs_batch.py
mode: cluster
monitoring:
exposeDriverMetrics: true
exposeExecutorMetrics: true
prometheus:
jmxExporterJar: /opt/spark/jars/jmx_prometheus_javaagent-0.11.0.jar
pythonVersion: "3"
restartPolicy:
onSubmissionFailureRetries: 5
onSubmissionFailureRetryInterval: 20
type: OnFailure
sparkConf:
spark.kubernete篓.local.dirs.tmpfs: "true"
spark.kubernetes.namespace: sourabh
sparkVersion: 2.4.5
type: Python
status:
applicationState:
errorMessage: Driver Pod not found
state: FAILED
driverInfo:
podName: logs-batch-driver
webUIAddress: 10.100.127.207:4040
webUIPort: 4040
webUIServiceName: logs-batch-ui-svc
executionAttempts: 1
lastSubmissionAttemptTime: "2020-02-12T02:10:29Z"
sparkApplicationId: spark-a7e0ffc3eabc418a97c31d9d40b149d9
submissionAttempts: 1
submissionID: a3d11fdd-9403-40a9-a588-81f6e669e695
terminationTime: "2020-02-12T02:10:30Z"
Interestingly I don't see the updated fields in the spec triggered by the Prometheus monitoring configuration. Can you do a diff on spec between your original version and the version you get by running kubectl get?
liyinan926
on 12 Feb 2020
Sorry I was too quick to conclusion. We actually have updated to using the status subresource and UpdateStatus to update the status of SparkApplication only a while ago. So the updates made by the Prometheus monitoring config are not to blame. The describe output you pasted in https://github.com/GoogleCloudPlatform/spark-on-k8s-operator/issues/795#issuecomment-584910686 actually proved that because there doesn't seem any updates related to Prometheus monitoring. I'm not sure where the update to the spec is coming from.
liyinan926
on 12 Feb 2020
The different I see between the runs that work and not seems to be the second submit:
Events:
Type Reason Age From Message
---- ------ ---- ---- -------
Normal SparkApplicationAdded 5m10s spark-operator SparkApplication logs-batch was added, enqueuing it for submission
Normal SparkApplicationSpecUpdateProcessed 5m7s spark-operator Successfully processed spec update for SparkApplication logs-batch
Warning SparkApplicationPendingRerun 5m7s spark-operator SparkApplication logs-batch is pending rerun
Normal SparkApplicationSubmitted 5m3s (x2 over 5m7s) spark-operator SparkApplication logs-batch was submitted successfully
Normal SparkDriverRunning 3m55s spark-operator Driver logs-batch-driver is running
Is there a race here between the update being processed and the submit being called somehow.
sb2nov
on 12 Feb 2020
There seems to be some kind of racing condition here. I don't know where the update is coming from in your case. But it seems the error happened when the update happened right after the app got submitted. The update invalidated the submitted run and caused the driver pod to be deleted. On the other hand, the status update during submission caused a requeue and reconciliation and a check of the driver pod.
liyinan926
on 12 Feb 2020
Is there any more iteration on this issue? We start to see this issue too.
pudong7163
on 19 Feb 2020
@liyinan926 just wanted to check if there is anything I can help with ?
sb2nov
on 25 Feb 2020
One thing you can do is to do a kubectl get sparkapplication <your app> -o=yaml and do a diff on the output of that vs. the original spec of your app and see what has been updated. I don't really see where the updated was from in your case.
liyinan926
on 29 Feb 2020
Another thing I don't understand is the generation of your resource remains 1 even though there seemed an update to the spec. The field generation is supposed to be incremented on every spec update with the status subresource enabled.
liyinan926
on 29 Feb 2020
This issue seems related to the issue reported in #826 that was caused by applying default values in the wrong place. Specifically, the default values were applied in the onAdd method directly on the resource in the cache instead of on a copy of the resource. The changes applied to the resource in the informer cache then became visible to any subsequent reads of the resource from the cache. This seemed to be the source of the change that led to the event SparkApplicationSpecUpdateProcessed. The issue has been fixed in #832.
liyinan926
on 15 Mar 2020
Awesome, thank you so much. Will you be cutting a new release by any chance ?
sb2nov
on 15 Mar 2020
I have updated and pushed image gcr.io/spark-operator/spark-operator:v2.4.5-v1beta2-latest to include the fix. Can you give it a try and let me know if the issue reported here is resolved?
liyinan926
on 15 Mar 2020
we were hitting the same issue, I tried gcr.io/spark-operator/spark-operator:v2.4.5-v1beta2-latest and can confirm it solves the problem, when can we get an official release?
ekesken
on 19 Mar 2020
Can you give gcr.io/spark-operator/spark-operator:v2.4.5-v1beta2-latest an try and see if it fixes the issue?
liyinan926
on 19 Mar 2020
Can you give gcr.io/spark-operator/spark-operator:v2.4.5-v1beta2-latest an try and see if it fixes the issue?
@liyinan926 I already tried and it fixed the issue for us.
ekesken
on 19 Mar 2020
Tried it as well, seems to have fixed the underlying issue.
sb2nov
on 19 Mar 2020
@ekesken @sb2nov thanks for confirming! Will make a new bug fix release soon.
liyinan926
on 19 Mar 2020
The fix in #832 has been released in https://github.com/GoogleCloudPlatform/spark-on-k8s-operator/releases/tag/v1beta2-1.1.1-2.4.5.
liyinan926
on 19 Mar 2020
Related issues
jgardner04
路
5Comments
chenqin
路
3Comments
liyinan926
路
3Comments
liyinan926
路
7Comments
vivekjain123
路
3Comments
Most helpful comment
Still seeing the same issue.