You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@airflow.apache.org by GitBox <gi...@apache.org> on 2022/02/16 08:16:20 UTC
[GitHub] [airflow] bhavaniravi opened a new issue #21605: KubernetesPodOperator Fails on empty log line
bhavaniravi opened a new issue #21605:
URL: https://github.com/apache/airflow/issues/21605
### Apache Airflow Provider(s)
cncf-kubernetes
### Versions of Apache Airflow Providers
apache-airflow-providers-cncf-kubernetes==1!2.1.0
### Apache Airflow version
2.2.3 (latest released)
### Operating System
Debian GNU/Linux 10 (buster)
### Deployment
Astronomer
### Deployment details
_No response_
### What happened
Some `KubernetesPodOperator` tasks fail with an empty logline. From the following logs, you could see that `monitor_pod` function
1. continuously fails to get a timestamp in log message `Error parsing timestamp. Will continue execution but won't update timestamp`
2. Not able to fetch container logs `unable to retrieve container logs for docker://`
3. eventually failing with an empty log line `Exception: Log not in "{timestamp} {log}" format. Got:`
### What you expected to happen
_No response_
### How to reproduce
Not sure what really causes this issue but this [StackOverflow question](https://stackoverflow.com/questions/59929589/docker-cleaning-up-kubernetes-pod-logs-too-quickly) Docker cleaning up the logs?
### Anything else
**Complete log stacktrace***
```
[2022-02-07, 23:33:23 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:33:23 UTC] {pod_launcher.py:176} INFO - rpc error: code = DeadlineExceeded desc = context deadline exceeded
[2022-02-07, 23:33:24 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:35:24 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:35:24 UTC] {pod_launcher.py:176} INFO - unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a
[2022-02-07, 23:35:25 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:37:25 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:37:25 UTC] {pod_launcher.py:176} INFO - unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a
[2022-02-07, 23:37:26 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:39:26 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:39:26 UTC] {pod_launcher.py:176} INFO - unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a
[2022-02-07, 23:39:27 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:41:27 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:41:27 UTC] {pod_launcher.py:176} INFO - unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a
[2022-02-07, 23:41:28 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:43:28 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:43:28 UTC] {pod_launcher.py:176} INFO - unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a
[2022-02-07, 23:43:29 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:45:29 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:45:29 UTC] {pod_launcher.py:176} INFO - unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a
[2022-02-07, 23:45:30 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:47:30 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:47:30 UTC] {pod_launcher.py:176} INFO - unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a
[2022-02-07, 23:47:31 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:49:31 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:49:31 UTC] {pod_launcher.py:176} INFO - unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a
[2022-02-07, 23:49:32 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:51:32 UTC] {pod_launcher.py:231} ERROR - Error parsing timestamp. Will continue execution but won't update timestamp
[2022-02-07, 23:51:32 UTC] {pod_launcher.py:176} INFO - unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a
[2022-02-07, 23:51:33 UTC] {pod_launcher.py:192} WARNING - Pod dbt-hourly-run-task.537231fc6daf403484e342380a5caf53 log read interrupted
[2022-02-07, 23:51:56 UTC] {taskinstance.py:1700} ERROR - Task failed with exception
Traceback (most recent call last):
File "/usr/local/lib/python3.9/site-packages/airflow/models/taskinstance.py", line 1329, in _run_raw_task
self._execute_task_with_callbacks(context)
File "/usr/local/lib/python3.9/site-packages/airflow/models/taskinstance.py", line 1455, in _execute_task_with_callbacks
result = self._execute_task(context, self.task)
File "/usr/local/lib/python3.9/site-packages/airflow/models/taskinstance.py", line 1506, in _execute_task
result = execute_callable(context=context)
File "/usr/local/lib/python3.9/site-packages/airflow/providers/cncf/kubernetes/operators/kubernetes_pod.py", line 367, in execute
final_state, remote_pod, result = self.create_new_pod_for_operator(labels, launcher)
File "/usr/local/lib/python3.9/site-packages/airflow/providers/cncf/kubernetes/operators/kubernetes_pod.py", line 524, in create_new_pod_for_operator
final_state, remote_pod, result = launcher.monitor_pod(pod=self.pod, get_logs=self.get_logs)
File "/usr/local/lib/python3.9/site-packages/airflow/providers/cncf/kubernetes/utils/pod_launcher.py", line 175, in monitor_pod
timestamp, message = self.parse_log_line(line.decode('utf-8'))
File "/usr/local/lib/python3.9/site-packages/airflow/providers/cncf/kubernetes/utils/pod_launcher.py", line 225, in parse_log_line
raise Exception(f'Log not in "{{timestamp}} {{log}}" format. Got: {line}')
Exception: Log not in "{timestamp} {log}" format. Got:
```
### Are you willing to submit PR?
- [ ] Yes I am willing to submit a PR!
### Code of Conduct
- [X] I agree to follow this project's [Code of Conduct](https://github.com/apache/airflow/blob/main/CODE_OF_CONDUCT.md)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1079955383
@bhavaniravi I think the root cause of the problem is that you can't read the logs of the POD. This looks like misconfiguration of your service account.
The root cause of the problem is not parsing, nor even empty line but the fact that you cannot read the logs:
`unable to retrieve container logs for docker://c2cd33567efa4a95f555ccb6d7fda760b65bb9cf2d13087d2704e2e8b974e42a`
Maybe you should look closer at your k8s logs and see what is the root cause of the problem. Even if we add an extra step to "react" on empty lines it will not solve the root cause, which is inability to read the logs. Can any of those who has similar problems get a deeper look at your k8s logs and see if there are any other errors - for example indicating that thare are some permission issues or any other anomalies.
Looking at it as "parsing" issue is just masking a real problem you have in your deployment I am afraid.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1081049585
While we do not know the root cause, the #22566 should mitigate the crash. Will be released in the next provider (but the next provider will only be installable in 2.3.0 +).
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] bhavaniravi commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
bhavaniravi commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1041227645
I'm not sure of the root cause of the issue.
If the fix is as simple as handling empty log line I would be happy to raise a PR for the same
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] bhavaniravi edited a comment on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
bhavaniravi edited a comment on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1048491717
With reference to #15638 @dimberman, are you aware of a case where the log lines can be empty?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] aljanson commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
aljanson commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1076925130
Hello, I tried using the latest package version 3.1.1 but face the same issue as above, any recommendations?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk closed issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
potiuk closed issue #21605:
URL: https://github.com/apache/airflow/issues/21605
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] aljanson commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
aljanson commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1080009323
Just adding a little more context. I am using Airflow 2.x to spin up pods on an Azure Kubernetes Cluster using the KubernetesPodOperator operator.
Its interesting that I dont face the above logging issues when running the pod on a provisioned node. However, the moment I try to execute the same on the newer [virtual nodes](https://docs.microsoft.com/en-us/azure/aks/virtual-nodes), it starts hitting me with the logging error.
Furthermore, I've also noticed that if I disable the do_xcom_push argument, the job then succeeds just fine, however will still have those warning messages throughout the logs saying "Error parsing timestamp. Will continue execution but won't update timestamp".
On the documentation page for AKS [virtual nodes](https://docs.microsoft.com/en-us/azure/aks/virtual-nodes), it does mention that init containers are not supported. I believe, the way xcom works is by running a sidecar container however right? Just trying to make sense of any obvious limitations which I might be missing right off the bat :)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] bhavaniravi commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
bhavaniravi commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1042529397
3.0.2 Also has the same logic for parsing log lines, wouldn't be of much help
https://github.com/apache/airflow/blob/providers-cncf-kubernetes/3.0.2/airflow/providers/cncf/kubernetes/utils/pod_manager.py#L254
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] bhavaniravi commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
bhavaniravi commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1048491717
with reference to #15638 @dimberman are you aware of a case where the log lines can be empty?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] aljanson edited a comment on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
aljanson edited a comment on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1084010727
Thanks @potiuk, however what fix/workaround can we use in the interim for this to prevent the errors and the crashing until the above is released? (as 2.3.0 release seems far away)
Is there a possibility of using a custom Xcom backend (s3) with the pod operator instead of the default writing to the side-car container?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] aljanson edited a comment on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
aljanson edited a comment on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1084010727
Thanks! however what fix/workaround can we use in the interim for this to prevent the errors and the crashing until the above is released? (as 2.3.0 release seems far away)
Is there a possibility of using a custom Xcom backend (s3) with the pod operator instead of the default writing to the side-car container?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] aljanson edited a comment on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
aljanson edited a comment on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1084010727
Thanks @potiuk, however what fix/workaround can we use in the interim for this to prevent the errors and the crashing until the above is released? (as 2.3.0 release seems far away)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] aljanson edited a comment on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
aljanson edited a comment on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1080009323
@potiuk Just adding a little more context. I am using Airflow 2.x to spin up pods on an Azure Kubernetes Cluster using the KubernetesPodOperator operator.
Its interesting that I dont face the above logging issues when running the pod on a provisioned node. However, the moment I try to execute the same on the newer [virtual nodes](https://docs.microsoft.com/en-us/azure/aks/virtual-nodes), it starts hitting me with the logging error.
Furthermore, I've also noticed that if I disable the do_xcom_push argument, the job then succeeds just fine, however will still have those warning messages throughout the logs saying "Error parsing timestamp. Will continue execution but won't update timestamp".
On the documentation page for AKS [virtual nodes](https://docs.microsoft.com/en-us/azure/aks/virtual-nodes), it does mention that init containers are not supported. I believe, the way xcom works is by running a sidecar container however right? Just trying to make sense of any obvious limitations which I might be missing right off the bat :)
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] aljanson commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
aljanson commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1084010727
Thanks @potiuk, however what fix/workaround can we use in the interim for this to prevent the errors and the crashing until the above is released?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] raphaelauv commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
raphaelauv commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1041584966
Could you try update to latest version of the provider https://pypi.org/project/apache-airflow-providers-cncf-kubernetes/
3.0.2
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #21605: KubernetesPodOperator Fails on empty log line
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #21605:
URL: https://github.com/apache/airflow/issues/21605#issuecomment-1060110968
> 3.0.2 Also has the same logic for parsing log lines, wouldn't be of much help https://github.com/apache/airflow/blob/providers-cncf-kubernetes/3.0.2/airflow/providers/cncf/kubernetes/utils/pod_manager.py#L254
It has different kubernetes library. Can you please chack it ?
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@airflow.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org