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 2020/12/09 20:21:53 UTC
[GitHub] [airflow] arijitdey opened a new issue #12969: S3 Remote Logging not working
arijitdey opened a new issue #12969:
URL: https://github.com/apache/airflow/issues/12969
<!--
Welcome to Apache Airflow! For a smooth issue process, try to answer the following questions.
Don't worry if they're not all applicable; just try to include what you can :-)
If you need to include code snippets or logs, please put them in fenced code
blocks. If they're super-long, please use the details tag like
<details><summary>super-long log</summary> lots of stuff </details>
Please delete these comment blocks before submitting the issue.
-->
<!--
IMPORTANT!!!
PLEASE CHECK "SIMILAR TO X EXISTING ISSUES" OPTION IF VISIBLE
NEXT TO "SUBMIT NEW ISSUE" BUTTON!!!
PLEASE CHECK IF THIS ISSUE HAS BEEN REPORTED PREVIOUSLY USING SEARCH!!!
Please complete the next sections or the issue will be closed.
These questions are the first thing we need to know to understand the context.
-->
**Apache Airflow version**: v2.0.0b3
**Kubernetes version (if you are using kubernetes)** (use `kubectl version`): 1.16.15
**Environment**:
- **Cloud provider or hardware configuration**: AWS
- **OS** (e.g. from /etc/os-release):
- **Kernel** (e.g. `uname -a`):
- **Install tools**: Custom Helm Chart
- **Others**:
**What happened**:
S3 Remote Logging not working. Below is the stacktrace:
```
Running <TaskInstance: canary_dag.print_date 2020-12-09T19:46:17.200838+00:00 [queued]> on host canarydagprintdate-9fafada4409d4eafb5e6e9c7187810ae │
│ [2020-12-09 19:54:09,825] {s3_task_handler.py:183} ERROR - Could not verify previous log to append: 'NoneType' object is not callable │
│ Traceback (most recent call last): │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py", line 179, in s3_write │
│ if append and self.s3_log_exists(remote_log_location): │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py", line 141, in s3_log_exists │
│ return self.hook.check_for_key(remote_log_location) │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 57, in wrapper │
│ connection = self.get_connection(self.aws_conn_id) │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/hooks/base.py", line 63, in get_connection │
│ conn = Connection.get_connection_from_secrets(conn_id) │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/models/connection.py", line 351, in get_connection_from_secrets │
│ conn = secrets_backend.get_connection(conn_id=conn_id) │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/utils/session.py", line 64, in wrapper │
│ with create_session() as session: │
│ File "/usr/local/lib/python3.7/contextlib.py", line 112, in __enter__ │
│ return next(self.gen) │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/utils/session.py", line 29, in create_session │
│ session = settings.Session() │
│ TypeError: 'NoneType' object is not callable │
│ [2020-12-09 19:54:09,826] {s3_task_handler.py:193} ERROR - Could not write logs to s3://my-favorite-airflow-logs/canary_dag/print_date/2020-12-09T19:46:17.200838+00:00/2.log │
│ Traceback (most recent call last): │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py", line 190, in s3_write │
│ encrypt=conf.getboolean('logging', 'ENCRYPT_S3_LOGS'), │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 57, in wrapper │
│ connection = self.get_connection(self.aws_conn_id) │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/hooks/base.py", line 63, in get_connection │
│ conn = Connection.get_connection_from_secrets(conn_id) │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/models/connection.py", line 351, in get_connection_from_secrets │
│ conn = secrets_backend.get_connection(conn_id=conn_id) │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/utils/session.py", line 64, in wrapper │
│ with create_session() as session: │
│ File "/usr/local/lib/python3.7/contextlib.py", line 112, in __enter__ │
│ return next(self.gen) │
│ File "/home/airflow/.local/lib/python3.7/site-packages/airflow/utils/session.py", line 29, in create_session │
│ session = settings.Session() │
│ TypeError: 'NoneType' object is not callable
stream closed
```
**What you expected to happen**
Able to see the task instance logs in the airflow UI being read from S3 remote location.
**How to reproduce it**:
Pulled the latest master and created an airflow image from the dockerfile mentioned in the repo.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744327352
The cached hook does not help because it reads connection in @providebucket_name wrapper.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744337651
> So we now have a question to ask. Given it can be worked around with a config change and a provider change (The provider could possibly even "force" this config change for us at run time!), do we make this change in an RC3 or a 2.0.1?
See above ^^ this is much worse. I think S3 task handler will never work in atexit.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744433856
`raw` is `ti.raw`, i.e. when we do `airflow task run --raw`
The "raw" task is the one that actually executes the task code, without raw it is the "supervisor" process.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744085439
No, the #13048 does not seem to help (I tried the S3 part of the fix). It really looks like the "fork + multiprocessing" error. When I hard-code the CAN_FORK = False, I got the close() called, but with the "NoneType' error.
When I apply the fix to the S3TaskHandler from #13048 - it does not help. I added some debug code to know for sure when the 'close()' method has been called - and it is not called at all when "CAN_FORK" evaluates to true:
```
def close(self):
"""Close and upload local log file to remote storage S3."""
# When application exit, system shuts down all handlers by
# calling close method. Here we check if logger is already
# closed to prevent uploading the log to remote storage multiple
# times when `logging.shutdown` is called.
with open ("/tmp/out.txt", "at") as f:
f.write("Closing\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.closed:
return
super().close()
if not self.upload_on_close:
return
local_loc = os.path.join(self.local_base, self.log_relative_path)
remote_loc = os.path.join(self.remote_base, self.log_relative_path)
if os.path.exists(local_loc):
# read log and remove old logs to get just the latest additions
with open(local_loc) as logfile:
log = logfile.read()
self.s3_write(log, remote_loc)
```
I see this method being called once from the main scheduler process and appending this to the log:
```
Closing
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
It does not add anything to S3 because there is no file (just folder) named `/root/airflow/logs`
If I modify 'CAN_FORK=False' I got another entry there:
```
Closing
example_bash_operator/runme_0/2020-12-13T22:51:17.397960+00:00/1.log
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/runme_0/2020-12-13T22:51:17.397960+00:00/1.log
```
Which is much closer to what I would expect, but then I got the 'NoneType' object is not callale exception above.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744310938
It's quite east to reproduce for me:
1) I firs applied https://github.com/apache/airflow/pull/13055 to solve incompatibility of Airflow with snowflake https://github.com/apache/airflow/pull/13056
2) in files/airflow-breeze-config/init.sh I added this:
```
AIRFLOW__LOGGING__REMOTE_LOGGING="True"
AIRFLOW__LOGGING__ENCRYPT_S3_LOGS="False"
AIRFLOW__LOGGING__REMOTE_LOG_CONN_ID="aws_default"
AIRFLOW__LOGGING__REMOTE_BASE_LOG_FOLDER="s3://test-amazon-logging/airflowlogs"
AWS_ACCESS_KEY_ID="<REDACTED>"
AWS_SECRET_ACCESS_KEY="<REDACED>"
```
3) Started Airflow
```
./breeze start-airflow --backend postgres --load-example-dags --load-default-connections --install-airflow-version 2.0.0rc2 \
--skip-mounting-local-sources --extras "amazon" --python 3.8
```
3) I modified the installed airflow code to see whether the set_context() and close() have been called in S3TaskHandler:
Modified: `/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py`
I added also the proposal from you (self.hook) at the end of set_context()
```
def set_context(self, ti):
super().set_context(ti)
# Local location and remote location is needed to open and
# upload local log file to S3 remote storage.
self.log_relative_path = self._render_filename(ti, ti.try_number)
self.upload_on_close = not ti.raw
# Clear the file first so that duplicate data is not uploaded
# when re-using the same path (e.g. with rescheduled sensors)
with open ("/tmp/set_context.txt", "at") as f:
f.write("Set context\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.upload_on_close:
with open(self.handler.baseFilename, 'w'):
pass
# Ensure the hook is connected now -- at close time we will have
# already disconnected from the DB
self.hook
def close(self):
"""Close and upload local log file to remote storage S3."""
# When application exit, system shuts down all handlers by
# calling close method. Here we check if logger is already
# closed to prevent uploading the log to remote storage multiple
# times when `logging.shutdown` is called.
with open ("/tmp/closing.txt", "at") as f:
f.write("Closing\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.closed:
return
super().close()
if not self.upload_on_close:
return
local_loc = os.path.join(self.local_base, self.log_relative_path)
remote_loc = os.path.join(self.remote_base, self.log_relative_path)
if os.path.exists(local_loc):
# read log and remove old logs to get just the latest additions
with open(local_loc) as logfile:
log = logfile.read()
self.s3_write(log, remote_loc)
```
4) I kill and restart scheduler:
5) I run `tail -f` on both files:
At this point, e both set context and close were called once (with empty relative paths). I think this call is unnecessary, and this is another problem but it does not introduce any side effects so I ignore it for now. It shows however, that the handlers works.
set_context.txt:
```
Set context
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
closing.txt:
```
Closing
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
6) I manually (via UI) trigger example_bash_operator
7) set_context is called all right
```
Set context is called once
example_bash_operator/run_after_loop/2020-12-13T22:51:17.397960+00:00/1.log
False
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/run_after_loop/2020-12-13T22:51:17.397960+00:00/1.log
```
But close() is not.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744317850
It partially helps:
```
[2020-12-14 09:44:09,987] {s3_task_handler.py:208} ERROR - Could not write logs to s3://test-amazon-logging/airflowlogs/example_bash_operator/run_afte│172.23.0.1 - - [14/Dec/2020:09:44:05 +0000] "POST /last_dagruns HTTP/1.1" 200 202 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) App
r_loop/2020-12-14T09:44:05.331058+00:00/1.log │leWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
Traceback (most recent call last): │172.23.0.1 - - [14/Dec/2020:09:44:05 +0000] "POST /blocked HTTP/1.1" 200 117 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) AppleWeb
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py", line 201, in s3_write │Kit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
self.hook.load_string( │172.23.0.1 - - [14/Dec/2020:09:44:05 +0000] "POST /task_stats HTTP/1.1" 200 24117 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) App
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 57, in wrapper │leWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
connection = self.get_connection(self.aws_conn_id) │[2020-12-14 09:44:07 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/hooks/base.py", line 63, in get_connection │[2020-12-14 09:44:07 +0000] [934441] [INFO] Booting worker with pid: 934441
conn = Connection.get_connection_from_secrets(conn_id) │[2020-12-14 09:44:10 +0000] [1098] [INFO] Handling signal: ttou
File "/usr/local/lib/python3.8/site-packages/airflow/models/connection.py", line 351, in get_connection_from_secrets │[2020-12-14 09:44:10 +0000] [908605] [INFO] Worker exiting (pid: 908605)
conn = secrets_backend.get_connection(conn_id=conn_id) │[2020-12-14 09:44:38 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/utils/session.py", line 64, in wrapper │[2020-12-14 09:44:38 +0000] [942004] [INFO] Booting worker with pid: 942004
with create_session() as session: │[2020-12-14 09:44:41 +0000] [1098] [INFO] Handling signal: ttou
File "/usr/local/lib/python3.8/contextlib.py", line 113, in __enter__ │[2020-12-14 09:44:41 +0000] [916301] [INFO] Worker exiting (pid: 916301)
return next(self.gen) │[2020-12-14 09:45:08 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/utils/session.py", line 29, in create_session │[2020-12-14 09:45:08 +0000] [949507] [INFO] Booting worker with pid: 949507
session = settings.Session() │[2020-12-14 09:45:11 +0000] [1098] [INFO] Handling signal: ttou
TypeError: 'NoneType' object is not callable
```
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-742379941
I think it's because the logging configuration that got changed.
It changed from "core" to "logging" section:
('logging', 'encrypt_s3_logs'): ('core', 'encrypt_s3_logs'),
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] savferrara commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
savferrara commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-743174030
Can confirm, same issue with airflow2.0.0rc1 on Kubernetes 1.16 on EKS. With web "sync" worker I can read logs already in S3 (I just added some dummy files for testing) but workers are not writing any new logs into the S3 bucket.
**Airflow version:**
apache/airflow:2.0.0rc1-python3.8
**Env Variables:**
AIRFLOW__LOGGING__REMOTE_LOGGING: "False"
AIRFLOW__LOGGING__REMOTE_LOG_CONN_ID: "my_s3"
AIRFLOW__LOGGING__REMOTE_BASE_LOG_FOLDER: "s3://xxxxxx/Logs/aflogs"
AIRFLOW__LOGGING__ENCRYPT_S3_LOGS: "False"
**Provider package:**
apache-airflow-providers-amazon==1.0.0rc1
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744062884
Hey @ashb, @kaxil @mik-laj (since you were looking at similar problems before) - I think we have serious rc3 candidate here.
From my investigation, it looks like the S3 Handler's close() method is never called when the task finishes. Since we are using mulitprocessing, I beleive this is because the logging.shutdown() method is never executed. It is registered in logging via registering atexit, and it seems that the processes that are started via multiplrocessing technicaly do not execute the "atexit" method:
https://stackoverflow.com/questions/34506638/how-to-register-atexit-function-in-pythons-multiprocessing-subprocess
It looks like everything works fine until the close() method that is supposed to write the log.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744067783
I think it's not provider-specific :( @kaxil
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744310938
It's quite east to reproduce for me:
1) I firs applied https://github.com/apache/airflow/pull/13055 to solve incompatibility of Airflow with snowflake https://github.com/apache/airflow/pull/13056
2) in files/airflow-breeze-config/init.sh I added this:
```
AIRFLOW__LOGGING__REMOTE_LOGGING="True"
AIRFLOW__LOGGING__ENCRYPT_S3_LOGS="False"
AIRFLOW__LOGGING__REMOTE_LOG_CONN_ID="aws_default"
AIRFLOW__LOGGING__REMOTE_BASE_LOG_FOLDER="s3://test-amazon-logging/airflowlogs"
AWS_ACCESS_KEY_ID="<REDACTED>"
AWS_SECRET_ACCESS_KEY="<REDACED>"
```
3) Started Airflow
```
./breeze start-airflow --backend postgres --load-example-dags --load-default-connections --install-airflow-version 2.0.0rc2 \
--skip-mounting-local-sources --extras "amazon" --python 3.8
```
3) I modified the installed airflow code to see whether the set_context() and close() have been called in S3TaskHandler:
Modified: `/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py`
I added also the proposal from you (self.hook) at the end of set_context()
```
def set_context(self, ti):
super().set_context(ti)
# Local location and remote location is needed to open and
# upload local log file to S3 remote storage.
self.log_relative_path = self._render_filename(ti, ti.try_number)
self.upload_on_close = not ti.raw
# Clear the file first so that duplicate data is not uploaded
# when re-using the same path (e.g. with rescheduled sensors)
with open ("/tmp/set_context.txt", "at") as f:
f.write("Set context\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.upload_on_close:
with open(self.handler.baseFilename, 'w'):
pass
# Ensure the hook is connected now -- at close time we will have
# already disconnected from the DB
self.hook
def close(self):
"""Close and upload local log file to remote storage S3."""
# When application exit, system shuts down all handlers by
# calling close method. Here we check if logger is already
# closed to prevent uploading the log to remote storage multiple
# times when `logging.shutdown` is called.
with open ("/tmp/closing.txt", "at") as f:
f.write("Closing\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.closed:
return
super().close()
if not self.upload_on_close:
return
local_loc = os.path.join(self.local_base, self.log_relative_path)
remote_loc = os.path.join(self.remote_base, self.log_relative_path)
if os.path.exists(local_loc):
# read log and remove old logs to get just the latest additions
with open(local_loc) as logfile:
log = logfile.read()
self.s3_write(log, remote_loc)
```
3a) I also copied the template config just to be sure:
```
mkdir ${AIRFLOW_HOME}/config/
cp /usr/local/lib/python3.8/site-packages/airflow/config_templates/airflow_local_settings.py ${AIRFLOW_HOME}/config/
```
4) I kill and restart scheduler:
The template config is used all right:
```
root@6611da4b1a27:/opt/airflow# airflow scheduler
____________ _____________
____ |__( )_________ __/__ /________ __
____ /| |_ /__ ___/_ /_ __ /_ __ \_ | /| / /
___ ___ | / _ / _ __/ _ / / /_/ /_ |/ |/ /
_/_/ |_/_/ /_/ /_/ /_/ \____/____/|__/
[2020-12-14 09:37:40,496] {scheduler_job.py:1241} INFO - Starting the scheduler
[2020-12-14 09:37:40,496] {scheduler_job.py:1246} INFO - Processing each file at most -1 times
[2020-12-14 09:37:40,563] {dag_processing.py:250} INFO - Launched DagFileProcessorManager with pid: 842145
[2020-12-14 09:37:40,563] {scheduler_job.py:1751} INFO - Resetting orphaned tasks for active dag runs
[2020-12-14 09:37:40,568] {settings.py:52} INFO - Configured default timezone Timezone('UTC')
[2020-12-14 09:37:40,569] {settings.py:421} INFO - Loaded airflow_local_settings from /root/airflow/config/airflow_local_settings.py .
```
5) I run `tail -f` on both files:
At this point, e both set context and close were called once (with empty relative paths). I think this call is unnecessary, and this is another problem but it does not introduce any side effects so I ignore it for now. It shows however, that the handlers works.
set_context.txt:
```
Set context
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
closing.txt:
```
Closing
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
6) I manually (via UI) trigger example_bash_operator
7) set_context is called all right
```
Set context
example_bash_operator/run_after_loop/2020-12-13T22:51:17.397960+00:00/1.log
False
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/run_after_loop/2020-12-13T22:51:17.397960+00:00/1.log
```
But close() is not.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744086409
This seems like a `close encounter of a 3rd kind' for both logging + orm when we use fork + multiprocessing.
It looks like we can get either logging behavior or ORM session working (but not both) when the process exits.
Either we get ORM/session closing but logging.shutdown() is not called at all - or logging.shutdown() called but ORM session is reset to None by that time and failing the logging code.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744327352
The cached hook does not help because it reads connection in @provide_bucket_name decorator of load_string (hook is instantiated all right and cached).
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744323889
| I added also the proposal from you (self.hook) at the end of set_context()
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] kaxil commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
kaxil commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744067221
Also, if GCP logging works maybe we can find a fix in Amazon provider, that way we might be able to avoid rc3
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744067472
Is this revolving around that ? (Just some reading on the phone before I test it) https://pythonspeed.com/articles/python-multiprocessing/
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744348393
Alright @potiuk, can you give #13057 a try. That fixed it for me.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744086409
This seems like \close encounter of a 3rd kind' for both logging + orm when we use fork + multiprocessing.
It looks like we can get either logging behavior or ORM session working (but not both) when the process exits.
Either we get ORM/session closing but logging.shutdown() is not called at all - or logging.shutdown() called but ORM session is reset to None by that time and failing the logging code.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] wyndhblb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
wyndhblb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-743228457
Adding some debug logging to things confirms as well, the sessionis being closed before the logger is run.
```
export AIRFLOW__LOGGING__LOGGING_LEVEL=debug
aiflow tasks run dummydag dummtasks "2020-12-10T00:00:00+00:00" --local --pool default_pool --subdir /dags/dummydag.py
Running <TaskInstance: dummydag.dummtasks2020-12-10T00:00:00+00:00 [success]> on host bobotest
[2020-12-11 14:34:03,358] {cli_action_loggers.py:84} DEBUG - Calling callbacks: []
[2020-12-11 14:34:03,358] {base.py:337} DEBUG - No metrics to flush. Continuing.
[2020-12-11 14:34:03,359] {base.py:345} DEBUG - No distributions to flush. Continuing.
[2020-12-11 14:34:03,359] {base.py:355} DEBUG - No events to flush. Continuing.
[2020-12-11 14:34:03,359] {settings.py:290} DEBUG - Disposing DB connection pool (PID 30)
[2020-12-11 14:34:03,367] {s3_task_handler.py:183} ERROR - Could not verify previous log to append: 'NoneType' object is not callable
```
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744273351
> for many task handlers, we have system tests. I will try to run these tests.
Handlers work all right - I checked them (at least S3 works fine and write logs when close() is called). I am not sure if we have system tests that run forking/process exiting. It looks like we have two independent problems in fact:
1) logging.shutdown is not called even if registered by atexit() when forking is used
2) when forking is disabled, login.shutddown is called all right, but it is called after the `dispose_orm` method gets called by atexit handler before: `atexit.register(dispose_orm)` in settings.py. Then retrieving the connection in s3_task_handler fails because it tries to read the connection from databse
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744296413
@potiuk What makes you think close isn't called? In my testing I see it being called.
Ah my tests were wrong.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] boring-cyborg[bot] commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
boring-cyborg[bot] commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-742025388
Thanks for opening your first issue here! Be sure to follow the issue template!
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744082484
@ashb -> tested "CAN_FORK=False' -> close() has been called but got the error mentioned before:
```
[2020-12-13 22:51:23,645] {s3_task_handler.py:204} ERROR - Could not write logs to s3://test-amazon-logging/airflowlogs/example_bash_operator/run_afte│172.23.0.1 - - [13/Dec/2020:22:51:17 +0000] "POST /dag_stats HTTP/1.1" 200 7189 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) Apple
r_loop/2020-12-13T22:51:17.397960+00:00/1.log │WebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
Traceback (most recent call last): │172.23.0.1 - - [13/Dec/2020:22:51:17 +0000] "POST /blocked HTTP/1.1" 200 117 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) AppleWeb
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py", line 197, in s3_write │Kit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
self.hook.load_string( │172.23.0.1 - - [13/Dec/2020:22:51:17 +0000] "POST /last_dagruns HTTP/1.1" 200 202 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) App
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 57, in wrapper │leWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
connection = self.get_connection(self.aws_conn_id) │172.23.0.1 - - [13/Dec/2020:22:51:17 +0000] "POST /task_stats HTTP/1.1" 200 24117 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) App
File "/usr/local/lib/python3.8/site-packages/airflow/hooks/base.py", line 63, in get_connection │leWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
conn = Connection.get_connection_from_secrets(conn_id) │[2020-12-13 22:51:23 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/models/connection.py", line 351, in get_connection_from_secrets │[2020-12-13 22:51:23 +0000] [3888562] [INFO] Booting worker with pid: 3888562
conn = secrets_backend.get_connection(conn_id=conn_id) │[2020-12-13 22:51:26 +0000] [1098] [INFO] Handling signal: ttou
File "/usr/local/lib/python3.8/site-packages/airflow/utils/session.py", line 64, in wrapper │[2020-12-13 22:51:26 +0000] [3877789] [INFO] Worker exiting (pid: 3877789)
with create_session() as session: │[2020-12-13 22:51:54 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/contextlib.py", line 113, in __enter__ │[2020-12-13 22:51:54 +0000] [3896167] [INFO] Booting worker with pid: 3896167
return next(self.gen) │[2020-12-13 22:51:57 +0000] [1098] [INFO] Handling signal: ttou
File "/usr/local/lib/python3.8/site-packages/airflow/utils/session.py", line 29, in create_session │[2020-12-13 22:51:57 +0000] [3877830] [INFO] Worker exiting (pid: 3877830)
session = settings.Session() │[2020-12-13 22:52:24 +0000] [1098] [INFO] Handling signal: ttin
TypeError: 'NoneType' object is not callable
```
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744273351
> for many task handlers, we have system tests. I will try to run these tests.
Handlers work all right - I checked them (at least S3 works fine and write logs when close() is called). I am not sure if we have system tests that run forking/process exiting. It looks like we have two independent problems in fact:
1) logging.shutdown is not called even if registered by atexit() when forking is used
2) when forking is disabled, login.shutddown is called all right, but it is called after the `dispose_orm` method gets called by atexit handler before: `atexit.register(dispose_orm)` in settings.py. Then retrieving the connection in s3_task_handler fails because it tries to read the connection from databse/orm and the form is already 'finalized'
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744066351
And is this only a problem with S3, or with all remote log backends?
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744338059
> RuntimeError: cannot schedule new futures after interpreter shutdown
Looks like a new change (to make this error explicit) in Py 3.8 https://github.com/python/cpython/commit/c4b695f85e141f57d22d8edf7bc2c756da136918.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744336856
> The cached hook does not help because it reads connection in @provide_bucket_name decorator of load_string (hook is instantiated all right and cached).
Oh yes, that could also be fixed in the provider.
So we now have a question to ask. Given it can be worked around with a config change and a provider change (The provider could possibly even "force" this config change for us at run time!), do we make this change in an RC3 or a 2.0.1?
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744456115
> This is to stop a double upload -- only the supervisor should upload the log, as it will write a few more lines after the task process has finished.
I see!
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744087885
GCS logging is broken in the same way, right? And I guess WASB (Azure) too
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744310938
It's quite east to reproduce for me:
1) I firs applied https://github.com/apache/airflow/pull/13055 to solve incompatibility of Airflow with snowflake https://github.com/apache/airflow/pull/13056
2) in files/airflow-breeze-config/init.sh I added this:
```
AIRFLOW__LOGGING__REMOTE_LOGGING="True"
AIRFLOW__LOGGING__ENCRYPT_S3_LOGS="False"
AIRFLOW__LOGGING__REMOTE_LOG_CONN_ID="aws_default"
AIRFLOW__LOGGING__REMOTE_BASE_LOG_FOLDER="s3://test-amazon-logging/airflowlogs"
AWS_ACCESS_KEY_ID="<REDACTED>"
AWS_SECRET_ACCESS_KEY="<REDACED>"
```
3) Started Airflow
```
./breeze start-airflow --backend postgres --load-example-dags --load-default-connections --install-airflow-version 2.0.0rc2 \
--skip-mounting-local-sources --extras "amazon" --python 3.8
```
3) I modified the installed airflow code to see whether the set_context() and close() have been called in S3TaskHandler:
Modified: `/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py`
I added also the proposal from you (self.hook) at the end of set_context()
```
def set_context(self, ti):
super().set_context(ti)
# Local location and remote location is needed to open and
# upload local log file to S3 remote storage.
self.log_relative_path = self._render_filename(ti, ti.try_number)
self.upload_on_close = not ti.raw
# Clear the file first so that duplicate data is not uploaded
# when re-using the same path (e.g. with rescheduled sensors)
with open ("/tmp/set_context.txt", "at") as f:
f.write("Set context\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.upload_on_close:
with open(self.handler.baseFilename, 'w'):
pass
# Ensure the hook is connected now -- at close time we will have
# already disconnected from the DB
self.hook
def close(self):
"""Close and upload local log file to remote storage S3."""
# When application exit, system shuts down all handlers by
# calling close method. Here we check if logger is already
# closed to prevent uploading the log to remote storage multiple
# times when `logging.shutdown` is called.
with open ("/tmp/closing.txt", "at") as f:
f.write("Closing\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.closed:
return
super().close()
if not self.upload_on_close:
return
local_loc = os.path.join(self.local_base, self.log_relative_path)
remote_loc = os.path.join(self.remote_base, self.log_relative_path)
if os.path.exists(local_loc):
# read log and remove old logs to get just the latest additions
with open(local_loc) as logfile:
log = logfile.read()
self.s3_write(log, remote_loc)
```
3a) I also copied the template config just to be sure:
```
mkdir ${AIRFLOW_HOME}/config/
cp /usr/local/lib/python3.8/site-packages/airflow/config_templates/airflow_local_settings.py ${AIRFLOW_HOME}/config/
```
4) I kill and restart scheduler:
The template config is used all right:
```
root@6611da4b1a27:/opt/airflow# airflow scheduler
____________ _____________
____ |__( )_________ __/__ /________ __
____ /| |_ /__ ___/_ /_ __ /_ __ \_ | /| / /
___ ___ | / _ / _ __/ _ / / /_/ /_ |/ |/ /
_/_/ |_/_/ /_/ /_/ /_/ \____/____/|__/
[2020-12-14 09:37:40,496] {scheduler_job.py:1241} INFO - Starting the scheduler
[2020-12-14 09:37:40,496] {scheduler_job.py:1246} INFO - Processing each file at most -1 times
[2020-12-14 09:37:40,563] {dag_processing.py:250} INFO - Launched DagFileProcessorManager with pid: 842145
[2020-12-14 09:37:40,563] {scheduler_job.py:1751} INFO - Resetting orphaned tasks for active dag runs
[2020-12-14 09:37:40,568] {settings.py:52} INFO - Configured default timezone Timezone('UTC')
[2020-12-14 09:37:40,569] {settings.py:421} INFO - Loaded airflow_local_settings from /root/airflow/config/airflow_local_settings.py .
```
5) I run `tail -f` on both files:
At this point, e both set context and close were called once (with empty relative paths). I think this call is unnecessary, and this is another problem but it does not introduce any side effects so I ignore it for now. It shows however, that the handlers works.
set_context.txt:
```
Set context
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
closing.txt:
```
Closing
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
6) I manually (via UI) trigger example_bash_operator
7) set_context is called all right
```
Set context is called once
example_bash_operator/run_after_loop/2020-12-13T22:51:17.397960+00:00/1.log
False
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/run_after_loop/2020-12-13T22:51:17.397960+00:00/1.log
```
But close() is not.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744438178
> Seems that 'close()' is the only place the handler actually writes anything to s3, so if ti is not "raw" (not sure what it means at this moment), the log will not be written at all.
This is to stop a double upload -- only the supervisor should upload the log, as it will write a few more lines after the task process has finished.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] wyndhblb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
wyndhblb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-742993564
this does not seem to be a configuration thing.
The backtrace indicates it's trying to get the connection object and the `settings.Session()` has been nullified somehow and so it fails to get the session with which to query the metastore.
even w/ the `logging` section properly filled in, i'm seeing the same issue.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744336412
I experimented a bit and I think we have a 3rd problem. I registered manually logging.shutdown after dispose_orm (atexit handlers are executed in reverse order). We have protection against calling close() more than once, so this might even be a viable long term solution:
```
# Ensure we close DB connections at scheduler and gunicon worker terminationsa
atexit.register(dispose_orm)
atexit.register(logging.shutdown)
```
However we hit another problem with S3 handler:
```
[2020-12-14 10:11:01,886] {s3_task_handler.py:208} ERROR - Could not write logs to s3://test-amazon-logging/airflowlogs/example_bash_operator/run_after_loop/2020-12-14T10:10:56.444247+00:00/1.log
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py", line 201, in s3_write
self.hook.load_string(
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 61, in wrapper
return func(*bound_args.args, **bound_args.kwargs)
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 90, in wrapper
return func(*bound_args.args, **bound_args.kwargs)
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 547, in load_string
self._upload_file_obj(file_obj, key, bucket_name, replace, encrypt, acl_policy)
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 638, in _upload_file_obj
client.upload_fileobj(file_obj, bucket_name, key, ExtraArgs=extra_args)
File "/usr/local/lib/python3.8/site-packages/boto3/s3/inject.py", line 536, in upload_fileobj
future = manager.upload(
File "/usr/local/lib/python3.8/site-packages/s3transfer/manager.py", line 312, in upload
return self._submit_transfer(
File "/usr/local/lib/python3.8/site-packages/s3transfer/manager.py", line 468, in _submit_transfer
self._submission_executor.submit(
File "/usr/local/lib/python3.8/site-packages/s3transfer/futures.py", line 467, in submit
future = ExecutorFuture(self._executor.submit(task))
File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 181, in submit
raise RuntimeError('cannot schedule new futures after '
RuntimeError: cannot schedule new futures after interpreter shutdown
```
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744317850
setting `AIRFLOW__CORE__EXECUTE_TASKS_NEW_PYTHON_INTERPRETER=True` partially helps - we seem to hit the "ORM disposed" problem
```
[2020-12-14 09:44:09,987] {s3_task_handler.py:208} ERROR - Could not write logs to s3://test-amazon-logging/airflowlogs/example_bash_operator/run_afte│172.23.0.1 - - [14/Dec/2020:09:44:05 +0000] "POST /last_dagruns HTTP/1.1" 200 202 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) App
r_loop/2020-12-14T09:44:05.331058+00:00/1.log │leWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
Traceback (most recent call last): │172.23.0.1 - - [14/Dec/2020:09:44:05 +0000] "POST /blocked HTTP/1.1" 200 117 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) AppleWeb
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py", line 201, in s3_write │Kit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
self.hook.load_string( │172.23.0.1 - - [14/Dec/2020:09:44:05 +0000] "POST /task_stats HTTP/1.1" 200 24117 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) App
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 57, in wrapper │leWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
connection = self.get_connection(self.aws_conn_id) │[2020-12-14 09:44:07 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/hooks/base.py", line 63, in get_connection │[2020-12-14 09:44:07 +0000] [934441] [INFO] Booting worker with pid: 934441
conn = Connection.get_connection_from_secrets(conn_id) │[2020-12-14 09:44:10 +0000] [1098] [INFO] Handling signal: ttou
File "/usr/local/lib/python3.8/site-packages/airflow/models/connection.py", line 351, in get_connection_from_secrets │[2020-12-14 09:44:10 +0000] [908605] [INFO] Worker exiting (pid: 908605)
conn = secrets_backend.get_connection(conn_id=conn_id) │[2020-12-14 09:44:38 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/utils/session.py", line 64, in wrapper │[2020-12-14 09:44:38 +0000] [942004] [INFO] Booting worker with pid: 942004
with create_session() as session: │[2020-12-14 09:44:41 +0000] [1098] [INFO] Handling signal: ttou
File "/usr/local/lib/python3.8/contextlib.py", line 113, in __enter__ │[2020-12-14 09:44:41 +0000] [916301] [INFO] Worker exiting (pid: 916301)
return next(self.gen) │[2020-12-14 09:45:08 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/utils/session.py", line 29, in create_session │[2020-12-14 09:45:08 +0000] [949507] [INFO] Booting worker with pid: 949507
session = settings.Session() │[2020-12-14 09:45:11 +0000] [1098] [INFO] Handling signal: ttou
TypeError: 'NoneType' object is not callable
```
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] savferrara edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
savferrara edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-743174030
Can confirm, same issue with airflow2.0.0rc1 on Kubernetes 1.16 on EKS. With web "sync" worker I can read logs already in S3 (I just added some dummy files for testing) but workers are not writing any new logs into the S3 bucket.
**Airflow version:**
apache/airflow:2.0.0rc1-python3.8
**Env Variables:**
AIRFLOW__LOGGING__REMOTE_LOGGING: "True"
AIRFLOW__LOGGING__REMOTE_LOG_CONN_ID: "my_s3"
AIRFLOW__LOGGING__REMOTE_BASE_LOG_FOLDER: "s3://xxxxxx/Logs/aflogs"
AIRFLOW__LOGGING__ENCRYPT_S3_LOGS: "False"
**Provider package:**
apache-airflow-providers-amazon==1.0.0rc1
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744062884
Hey @ashb, @kaxil @mik-laj (since you were looking at similar problems before) - I think we have serious rc3 candidate here.
From my investigation, it looks like the S3 Handler's close() method is never called when the task finishes. Since we are using mulitprocessing/forking, I beleive this is because the logging.shutdown() method is never executed. It is registered in logging via registering atexit, and it seems that the processes that are started via multiplrocessing technicaly do not execute the "atexit" method:
https://stackoverflow.com/questions/34506638/how-to-register-atexit-function-in-pythons-multiprocessing-subprocess
It looks like everything works fine until the close() method that is supposed to write the log.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744428607
Not entirely:
* For AIRFLOW__CORE__EXECUTE_TASKS_NEW_PYTHON_INTERPRETER=True I still got the "cannot schedule future""
* For 'False' seems that the S3 Task logger does not upload the file in case of Local Executor because "upload_on_close" is False
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744317850
setting `AIRFLOW__CORE__EXECUTE_TASKS_NEW_PYTHON_INTERPRETER=True` partially helps
```
[2020-12-14 09:44:09,987] {s3_task_handler.py:208} ERROR - Could not write logs to s3://test-amazon-logging/airflowlogs/example_bash_operator/run_afte│172.23.0.1 - - [14/Dec/2020:09:44:05 +0000] "POST /last_dagruns HTTP/1.1" 200 202 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) App
r_loop/2020-12-14T09:44:05.331058+00:00/1.log │leWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
Traceback (most recent call last): │172.23.0.1 - - [14/Dec/2020:09:44:05 +0000] "POST /blocked HTTP/1.1" 200 117 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) AppleWeb
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py", line 201, in s3_write │Kit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
self.hook.load_string( │172.23.0.1 - - [14/Dec/2020:09:44:05 +0000] "POST /task_stats HTTP/1.1" 200 24117 "http://localhost:28080/home" "Mozilla/5.0 (X11; Linux x86_64) App
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 57, in wrapper │leWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.88 Safari/537.36"
connection = self.get_connection(self.aws_conn_id) │[2020-12-14 09:44:07 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/hooks/base.py", line 63, in get_connection │[2020-12-14 09:44:07 +0000] [934441] [INFO] Booting worker with pid: 934441
conn = Connection.get_connection_from_secrets(conn_id) │[2020-12-14 09:44:10 +0000] [1098] [INFO] Handling signal: ttou
File "/usr/local/lib/python3.8/site-packages/airflow/models/connection.py", line 351, in get_connection_from_secrets │[2020-12-14 09:44:10 +0000] [908605] [INFO] Worker exiting (pid: 908605)
conn = secrets_backend.get_connection(conn_id=conn_id) │[2020-12-14 09:44:38 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/utils/session.py", line 64, in wrapper │[2020-12-14 09:44:38 +0000] [942004] [INFO] Booting worker with pid: 942004
with create_session() as session: │[2020-12-14 09:44:41 +0000] [1098] [INFO] Handling signal: ttou
File "/usr/local/lib/python3.8/contextlib.py", line 113, in __enter__ │[2020-12-14 09:44:41 +0000] [916301] [INFO] Worker exiting (pid: 916301)
return next(self.gen) │[2020-12-14 09:45:08 +0000] [1098] [INFO] Handling signal: ttin
File "/usr/local/lib/python3.8/site-packages/airflow/utils/session.py", line 29, in create_session │[2020-12-14 09:45:08 +0000] [949507] [INFO] Booting worker with pid: 949507
session = settings.Session() │[2020-12-14 09:45:11 +0000] [1098] [INFO] Handling signal: ttou
TypeError: 'NoneType' object is not callable
```
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744296413
@potiuk What makes you think close isn't called? In my testing I see it being called.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-742039338
Le t me know if this does not work (and i recommend to try rc1 just released). Also you can try 2.0.0rc1 images from our DockerHub - they have amazon provider preinstalled
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744065755
@potiuk can you edit https://github.com/apache/airflow/blob/master/airflow/settings.py#L471 and set it always to false. Does that help?
If so I have an idea the problem likely is.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744327352
The cached hook does not help because it reads connection in @provide_bucket_name wrapper (hook is instantiated all right and cached).
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] wyndhblb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
wyndhblb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-743248367
removing the `atexit` here --> https://github.com/apache/airflow/blob/master/airflow/settings.py#L439 allowed the s3 upload to succeed (not a solution, but further verification the session is being disposed before things are truly done)
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744324847
Ah I was testing with GCS and that doesn't seem to have the problem. Let me get my AWS cred set up on this laptop
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744314983
It appears that setting `AIRFLOW__CORE__EXECUTE_TASKS_NEW_PYTHON_INTERPRETER=True` helps.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] kaxil closed issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
kaxil closed issue #12969:
URL: https://github.com/apache/airflow/issues/12969
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] mik-laj commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
mik-laj commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744237666
for many task handlers, we have system tests. I will try to run these tests.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744314293
Everything looks legit in the `airflow info`:
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744323642
> My PR #13048 helps with that I think
Nope. I already added it in - see above snippet of 'set_context'
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744310938
It's quite easy to reproduce for me:
1) I firs applied https://github.com/apache/airflow/pull/13055 to solve incompatibility of Airflow with snowflake https://github.com/apache/airflow/pull/13056
2) in files/airflow-breeze-config/init.sh I added this:
```
AIRFLOW__LOGGING__REMOTE_LOGGING="True"
AIRFLOW__LOGGING__ENCRYPT_S3_LOGS="False"
AIRFLOW__LOGGING__REMOTE_LOG_CONN_ID="aws_default"
AIRFLOW__LOGGING__REMOTE_BASE_LOG_FOLDER="s3://test-amazon-logging/airflowlogs"
AWS_ACCESS_KEY_ID="<REDACTED>"
AWS_SECRET_ACCESS_KEY="<REDACED>"
```
3) Started Airflow
```
./breeze start-airflow --backend postgres --load-example-dags --load-default-connections --install-airflow-version 2.0.0rc2 \
--skip-mounting-local-sources --extras "amazon" --python 3.8
```
3) I modified the installed airflow code to see whether the set_context() and close() have been called in S3TaskHandler:
Modified: `/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py`
I added also the proposal from you (self.hook) at the end of set_context()
```
def set_context(self, ti):
super().set_context(ti)
# Local location and remote location is needed to open and
# upload local log file to S3 remote storage.
self.log_relative_path = self._render_filename(ti, ti.try_number)
self.upload_on_close = not ti.raw
# Clear the file first so that duplicate data is not uploaded
# when re-using the same path (e.g. with rescheduled sensors)
with open ("/tmp/set_context.txt", "at") as f:
f.write("Set context\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.upload_on_close:
with open(self.handler.baseFilename, 'w'):
pass
# Ensure the hook is connected now -- at close time we will have
# already disconnected from the DB
self.hook
def close(self):
"""Close and upload local log file to remote storage S3."""
# When application exit, system shuts down all handlers by
# calling close method. Here we check if logger is already
# closed to prevent uploading the log to remote storage multiple
# times when `logging.shutdown` is called.
with open ("/tmp/closing.txt", "at") as f:
f.write("Closing\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.closed:
return
super().close()
if not self.upload_on_close:
return
local_loc = os.path.join(self.local_base, self.log_relative_path)
remote_loc = os.path.join(self.remote_base, self.log_relative_path)
if os.path.exists(local_loc):
# read log and remove old logs to get just the latest additions
with open(local_loc) as logfile:
log = logfile.read()
self.s3_write(log, remote_loc)
```
3a) I also copied the template config just to be sure:
```
mkdir ${AIRFLOW_HOME}/config/
cp /usr/local/lib/python3.8/site-packages/airflow/config_templates/airflow_local_settings.py ${AIRFLOW_HOME}/config/
```
4) I kill and restart scheduler:
The template config is used all right:
```
root@6611da4b1a27:/opt/airflow# airflow scheduler
____________ _____________
____ |__( )_________ __/__ /________ __
____ /| |_ /__ ___/_ /_ __ /_ __ \_ | /| / /
___ ___ | / _ / _ __/ _ / / /_/ /_ |/ |/ /
_/_/ |_/_/ /_/ /_/ /_/ \____/____/|__/
[2020-12-14 09:37:40,496] {scheduler_job.py:1241} INFO - Starting the scheduler
[2020-12-14 09:37:40,496] {scheduler_job.py:1246} INFO - Processing each file at most -1 times
[2020-12-14 09:37:40,563] {dag_processing.py:250} INFO - Launched DagFileProcessorManager with pid: 842145
[2020-12-14 09:37:40,563] {scheduler_job.py:1751} INFO - Resetting orphaned tasks for active dag runs
[2020-12-14 09:37:40,568] {settings.py:52} INFO - Configured default timezone Timezone('UTC')
[2020-12-14 09:37:40,569] {settings.py:421} INFO - Loaded airflow_local_settings from /root/airflow/config/airflow_local_settings.py .
```
5) I run `tail -f` on both files:
At this point, e both set context and close were called once (with empty relative paths). I think this call is unnecessary, and this is another problem but it does not introduce any side effects so I ignore it for now. It shows however, that the handlers works.
set_context.txt:
```
Set context
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
closing.txt:
```
Closing
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
6) I manually (via UI) trigger example_bash_operator
7) set_context is called all right
```
Set context
example_bash_operator/run_after_loop/2020-12-13T22:51:17.397960+00:00/1.log
False
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/run_after_loop/2020-12-13T22:51:17.397960+00:00/1.log
```
But close() is not.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744314293
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-742037726
You need to install amazon provider for S3 logging.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744085439
No, the #13048 does not seem to help (I tried the S3 part of the fix). It really looks like the "fork + multiprocessing" error. When I hard-code the CAN_FORK = False, I got the close() called, but with the "NoneType' error. When I apply the fix to the S3TaskHandler from #13048 - it does not help. i added some debug code to know for sure when the 'close()' method has been called - and it is not called at all when "CAN_FORK" evaluates to true:
```
def close(self):
"""Close and upload local log file to remote storage S3."""
# When application exit, system shuts down all handlers by
# calling close method. Here we check if logger is already
# closed to prevent uploading the log to remote storage multiple
# times when `logging.shutdown` is called.
with open ("/tmp/out.txt", "at") as f:
f.write("Closing\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.closed:
return
super().close()
if not self.upload_on_close:
return
local_loc = os.path.join(self.local_base, self.log_relative_path)
remote_loc = os.path.join(self.remote_base, self.log_relative_path)
if os.path.exists(local_loc):
# read log and remove old logs to get just the latest additions
with open(local_loc) as logfile:
log = logfile.read()
self.s3_write(log, remote_loc)
```
I see this method being called once from the main scheduler process and appending this to the log:
```
Closing
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
It does not add anything to S3 because there is no file (just folder) named `/root/airflow/logs`
If I modify 'CAN_FORK=False' I got another entry there:
```
Closing
example_bash_operator/runme_0/2020-12-13T22:51:17.397960+00:00/1.log
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/runme_0/2020-12-13T22:51:17.397960+00:00/1.log
```
Which is much closer to what I would expect, but then I got the 'NoneType' object is not callale exception above.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744431738
```
Closing
example_bash_operator/run_after_loop/2020-12-14T13:02:08.462186+00:00/1.log
False
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/run_after_loop/2020-12-14T13:02:08.462186+00:00/1.log
```
I am also not sure why we have the 'upload_on_close=not ti.raw" at all.
Seems that 'close()' is the only place the handler actually writes anything to s3, so if ti is not "raw" (not sure what it means at this moment), the log will not be written at all.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744273351
> for many task handlers, we have system tests. I will try to run these tests.
Handlers work all right - I checked them (at least S3 works fine and write logs when close() is called). I am not sure if we have system tests that run forking/process exiting. It looks like we have two independent problems in fact:
1) logging.shutdown is not called even if registered by atexit() when forking is used
2) when forking is disabled, login.shutddown is called all right, but it is called after the `dispose_orm` method gets called by atexit handler before: `atexit.register(dispose_orm)` in settings.py. Then retrieving the connection in s3_task_handler fails because it tries to read the connection from databse/orm and the orm sqlachemy is already in `disposed' state.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744325612
The connection problem is likely easy to fix (and provider-specific), I think the close() not being called is something in core airflow though that needs to be fixed.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744087423
"The title (which is never specifically explained in the movie) is actually derived from Hynek’s own alien close encounter classification system: A close encounter of the first kind is sighting of a UFO; the second kind is physical evidence to prove the existence of an alien; and the third kind is actual contact with alien life forms."
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744344638
Alright, I'm working on a fix for all of these problems.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744067861
https://github.com/apache/airflow/pull/13048 might help - can you try that?
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744067783
I think it's not provider-specific :(
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744431738
```
Closing
example_bash_operator/run_after_loop/2020-12-14T13:02:08.462186+00:00/1.log
False
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/run_after_loop/2020-12-14T13:02:08.462186+00:00/1.log
```
I am also not sure why we have the 'upload_on_close=not ti.raw" at all.
Seems that 'close()' is the only place the handler actually writes anything to s3, so if ti is not "raw" (not sure what it means in this moment), the log will not be written at all.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744273351
> for many task handlers, we have system tests. I will try to run these tests.
Handlers work all right - I checked them (at least S3 works fine and write logs when close() is called). I am not sure if we have system tests that run forking/process exiting. It looks like we have two independent problems in fact:
1) logging.shutdown is not called even if registered by atexit() when forking is used
2) when forking is disabled, login.shutddown is called all right, but if is called after the `dispose_orm` metho gets called by atexit handler (`atexit.register(dispose_orm)` in settings.py) and then retrieving the connection in s3_task_handler fails because it tries to read the connection from databse
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744338059
> RuntimeError: cannot schedule new futures after interpreter shutdown
Looks like a new change (to make this error explicit) in Py 3.8 https://github.com/python/cpython/commit/c4b695f85e141f57d22d8edf7bc2c756da136918. We can work around
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744085439
No, the #13048 does not seem to help (I tried the S3 fix). It really looks like the "fork + multiprocessing" error. When I hard-code the CAN_FORK = False, I got the close() called, but with the "NoneType' error. When I apply the fix to the S3TaskHandler from #13048 - it does not help. i added some debug code to know for sure when the 'close()' method has been called - and it is not called at all when "CAN_FORK" evaluates to true:
```
def close(self):
"""Close and upload local log file to remote storage S3."""
# When application exit, system shuts down all handlers by
# calling close method. Here we check if logger is already
# closed to prevent uploading the log to remote storage multiple
# times when `logging.shutdown` is called.
with open ("/tmp/out.txt", "at") as f:
f.write("Closing\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.closed:
return
super().close()
if not self.upload_on_close:
return
local_loc = os.path.join(self.local_base, self.log_relative_path)
remote_loc = os.path.join(self.remote_base, self.log_relative_path)
if os.path.exists(local_loc):
# read log and remove old logs to get just the latest additions
with open(local_loc) as logfile:
log = logfile.read()
self.s3_write(log, remote_loc)
```
I see this method being called once from the main scheduler process and appending this to the log:
```
Closing
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
It does not add anything to S3 because there is no file (just folder) named `/root/airflow/logs`
If I modify 'CAN_FORK=False' I got another entry there:
```
Closing
example_bash_operator/runme_0/2020-12-13T22:51:17.397960+00:00/1.log
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/runme_0/2020-12-13T22:51:17.397960+00:00/1.log
```
Which is much closer to what I would expect, but then I got the 'NoneType' object is not callale exception above.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk closed issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk closed issue #12969:
URL: https://github.com/apache/airflow/issues/12969
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744273351
> for many task handlers, we have system tests. I will try to run these tests.
Handlers work all right - I checked them (at least S3 works fine and write logs when close() is called). I am not sure if we have system tests that run forking/process exiting. It looks like we have two independent problems in fact:
1) logging.shutdown is not called even if registered by atexit() when forking is used
2) when forking is disabled, login.shutddown is called all right, but it is called after the `dispose_orm` method gets called by atexit handler before (`atexit.register(dispose_orm)` in settings.py) and then retrieving the connection in s3_task_handler fails because it tries to read the connection from databse
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744085439
No, the #13048 does not seem to help (I tried the S3 part of the fix). It really looks like the "fork + multiprocessing" error. When I hard-code the CAN_FORK = False, I got the close() called, but with the "NoneType' error.
When I apply the fix to the S3TaskHandler from #13048 - it does not help. I added some debug code to know for sure when the 'close()' method has been called - and it is not called at all when "CAN_FORK" evaluates to true:
```
def close(self):
"""Close and upload local log file to remote storage S3."""
# When application exit, system shuts down all handlers by
# calling close method. Here we check if logger is already
# closed to prevent uploading the log to remote storage multiple
# times when `logging.shutdown` is called.
with open ("/tmp/out.txt", "at") as f:
f.write("Closing\n")
f.write(self.log_relative_path + "\n")
f.write(str(self.upload_on_close) + "\n")
f.write(self.local_base + "\n")
f.write(self.remote_base + "\n")
f.write(self.log_relative_path + "\n")
if self.closed:
return
super().close()
if not self.upload_on_close:
return
local_loc = os.path.join(self.local_base, self.log_relative_path)
remote_loc = os.path.join(self.remote_base, self.log_relative_path)
if os.path.exists(local_loc):
# read log and remove old logs to get just the latest additions
with open(local_loc) as logfile:
log = logfile.read()
self.s3_write(log, remote_loc)
```
I see this method being called once from the main scheduler process and appending this to the log:
```
Closing
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
```
It does not add anything to S3 because there is no file (just folder named `/root/airflow/logs`)
If I modify 'CAN_FORK=False' I got another entry there:
```
Closing
example_bash_operator/runme_0/2020-12-13T22:51:17.397960+00:00/1.log
True
/root/airflow/logs
s3://test-amazon-logging/airflowlogs
example_bash_operator/runme_0/2020-12-13T22:51:17.397960+00:00/1.log
```
Which is much closer to what I would expect, but then I got the 'NoneType' object is not callale exception above.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-742379941
I think it's becauset the logging configuration that got changed.
It changed from "core" to "logging" section:
('logging', 'encrypt_s3_logs'): ('core', 'encrypt_s3_logs'),
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744322078
My PR #13048 helps with that I think
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744088052
I think so. Havn't tried all of them - but the fact that 'close()' is not called makes me think all of them are affected.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-743176340
Thanks! I will take a look at this!
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-742381605
Can you please confirm this? If so, then we do not have fallback in the provider's task to the old configuration options (which we should have).
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] arijitdey commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
arijitdey commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-742342218
@potiuk Still getting the same error trace:
```
airflow@airflow-68964cf4bd-hm74g:/opt/airflow$ pip freeze | grep amazon
apache-airflow-providers-amazon==1.0.0rc1
```
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744061151
Confirmed in my tests with LocalExecutor seems that "close()" method is never called when the task finishes.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744337651
> So we now have a question to ask. Given it can be worked around with a config change and a provider change (The provider could possibly even "force" this config change for us at run time!), do we make this change in an RC3 or a 2.0.1?
See above ^^ this is much worse. I think S3 provider will never work in atexit.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] kaxil commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
kaxil commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744066982
We had logging.shutdown(), that was removed in this PR: https://github.com/apache/airflow/pull/12342
It was originally added in https://github.com/apache/airflow/pull/3259
Do we need to reintroduce it? Or find a better fix.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744336412
I experimented a bit and I think we have a 3rd problem. I registered manually logging.shutdown after dispose_orm (atexit handlers are executed in reverse order). We have protection against calling close() more than once, so this might even be a viable long term solution:
```
# Ensure we close DB connections at scheduler and gunicon worker terminationsa
atexit.register(dispose_orm)
atexit.register(logging.shutdown)
```
However we hit another problem with S3 handler:
```
[2020-12-14 10:11:01,886] {s3_task_handler.py:208} ERROR - Could not write logs to s3://test-amazon-logging/airflowlogs/example_bash_operator/run_after_loop/2020-12-14T10:10:56.444247+00:00/1.log
Traceback (most recent call last):
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/log/s3_task_handler.py", line 201, in s3_write
self.hook.load_string(
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 61, in wrapper
return func(*bound_args.args, **bound_args.kwargs)
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 90, in wrapper
return func(*bound_args.args, **bound_args.kwargs)
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 547, in load_string
self._upload_file_obj(file_obj, key, bucket_name, replace, encrypt, acl_policy)
File "/usr/local/lib/python3.8/site-packages/airflow/providers/amazon/aws/hooks/s3.py", line 638, in _upload_file_obj
client.upload_fileobj(file_obj, bucket_name, key, ExtraArgs=extra_args)
File "/usr/local/lib/python3.8/site-packages/boto3/s3/inject.py", line 536, in upload_fileobj
future = manager.upload(
File "/usr/local/lib/python3.8/site-packages/s3transfer/manager.py", line 312, in upload
return self._submit_transfer(
File "/usr/local/lib/python3.8/site-packages/s3transfer/manager.py", line 468, in _submit_transfer
self._submission_executor.submit(
File "/usr/local/lib/python3.8/site-packages/s3transfer/futures.py", line 467, in submit
future = ExecutorFuture(self._executor.submit(task))
File "/usr/local/lib/python3.8/concurrent/futures/thread.py", line 181, in submit
raise RuntimeError('cannot schedule new futures after '
RuntimeError: cannot schedule new futures after interpreter shutdown
```
Seems that sending logs from S3 in the "atexit" method is a bad idea in general as it has no chance to work there.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744434699
Fix for local executor comming.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744066078
Will check it when I am back at my pc.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744086409
This seems like a `close encounter of the 3rd kind' for both logging + orm when we use fork + multiprocessing.
It looks like we can get either logging behavior or ORM session working (but not both) when the process exits.
Either we get ORM/session closing but logging.shutdown() is not called at all - or logging.shutdown() called but ORM session is reset to None by that time and failing the logging code.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] ashb edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
ashb edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744314983
It appears that setting `AIRFLOW__CORE__EXECUTE_TASKS_NEW_PYTHON_INTERPRETER=True` helps, but at the cost of speed.
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744428607
Not entirely. The Close() is called now but:
* For AIRFLOW__CORE__EXECUTE_TASKS_NEW_PYTHON_INTERPRETER=True I still got the "cannot schedule future""
* For 'False' seems that the S3 Task logger does not upload the file in case of Local Executor because "upload_on_close" is False
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk edited a comment on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk edited a comment on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744323889
> I added also the proposal from you (self.hook) at the end of set_context()
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] potiuk commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
potiuk commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744082684
Trying the https://github.com/apache/airflow/pull/13048
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [airflow] mik-laj commented on issue #12969: S3 Remote Logging not working
Posted by GitBox <gi...@apache.org>.
mik-laj commented on issue #12969:
URL: https://github.com/apache/airflow/issues/12969#issuecomment-744300045
> I am not sure if we have system tests that run forking/process exiting.
Yes. I knew it was troublesome and the system tests were very high-level. All key operations are executed as a new process (spawn).
https://github.com/apache/airflow/blob/fdd9b6f65b608c516b8a062b058972d9a45ec9e3/tests/providers/google/cloud/log/test_gcs_task_handler_system.py#L75-L76
----------------------------------------------------------------
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.
For queries about this service, please contact Infrastructure at:
users@infra.apache.org