Skip to content

[AIRFLOW-1332] Split logs based on try number - #2383

Closed
allisonwang wants to merge 2 commits into
apache:masterfrom
allisonwang:allison--add-task-attempt
Closed

[AIRFLOW-1332] Split logs based on try number #2383
allisonwang wants to merge 2 commits into
apache:masterfrom
allisonwang:allison--add-task-attempt

Conversation

@allisonwang

@allisonwang allisonwang commented Jun 21, 2017

Copy link
Copy Markdown
Contributor

Dear Airflow maintainers,

Please accept this PR. I understand that it will not be reviewed until I have checked off all the steps below!

JIRA

  • My PR addresses the following Airflow 1332 issues and references them in the PR title.

Description

  • Here are some details about my PR, including screenshots of any UI changes:
    This PR splits logs based on try number and add tabs to display different task instance tries.
    screen shot 2017-07-11 at 11 44 10 am

Note this PR is a temporary change for separating task attempts. The code in this PR will be refactored in the future. Please refer to #2464 for Airflow logging abstractions redesign.

Tests

  • My PR adds the following unit tests OR does not need testing for this extremely good reason:
  1. Added unit tests.
  2. Tested on localhost.
  3. Tested on production environment with S3 remote storage, MySQL database, Redis, one Airflow scheduler and two airflow workers.

Commits

  • My commits all reference JIRA issues in their subject lines, and I have squashed multiple commits if they address the same issue. In addition, my commits follow the guidelines from "How to write a good git commit message":
    1. Subject is separated from body by a blank line
    2. Subject is limited to 50 characters
    3. Subject does not end with a period
    4. Subject uses the imperative mood ("add", not "adding")
    5. Body wraps at 72 characters
    6. Body explains "what" and "why", not "how"

@aoen @saguziel

@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch from aa1739f to 6dde129 Compare June 21, 2017 19:54
@bolkedebruin

Copy link
Copy Markdown
Contributor

I'm not very enthusiastic out this. I don't really see the use case for it.

@bolkedebruin bolkedebruin left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The updates to attempt are not atomic. I don't understand try_number vs attempt.

No tests supplied.

Comment thread airflow/bin/cli.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What are you doing with attempt? It is not used. The session is not committed and not closed.

In addition if you want to update the field make sure to read up on sqlalchemy's update mechanism in order not to end up with race conditions.

Comment thread airflow/bin/cli.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Don't access the database directly. Use models.py in order to
Make sure you load the right ti.

@allisonwang allisonwang Jun 22, 2017

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Just curious what could go wrong if I directly access db here?

Comment thread airflow/models.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Try number vs attempt?

@allisonwang

allisonwang commented Jun 21, 2017

Copy link
Copy Markdown
Contributor Author

@bolkedebruin To give more context, please also refer to this PR: #2380. This change is to enable us to display logs for each task retry/rerun in different tabs instead of one long document. The try_number / attempt is indeed confusing. Basically, it's a monotonically increasing field that keeps track of the number of times a certain task instance gets picked up and executed. Try_number would become 0 once the task gets cleared, but attempt would not change. In the future, it can be used as part of the name of the log file to separate each attempt.

@bolkedebruin

Copy link
Copy Markdown
Contributor

Mmm still not convinced. Especially on elastic search it is just easier to use the start_date to shard on.

In addition I'm very against the managing of log files this way. Log files are already a mess and should be refactored to be consistent and to be managed from one place. The docker packagers can already not package airflow correctly without jumping through hoops. Arbitrarily naming it certainly does not help here.

@allisonwang

Copy link
Copy Markdown
Contributor Author

@bolkedebruin I will send an email to airflow mailing list and let's move the discussion there :)

@bolkedebruin

Copy link
Copy Markdown
Contributor

Perfect.

@allisonwang allisonwang changed the title [AIRFLOW-1332] Add attempt column to task instance [AIRFLOW-1332][WIP] Add attempt column to task instance Jun 22, 2017
@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch from 6dde129 to 910f1a9 Compare June 27, 2017 19:04
@allisonwang allisonwang changed the title [AIRFLOW-1332][WIP] Add attempt column to task instance [AIRFLOW-1332][WIP] Split logs based on try number Jun 27, 2017
@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch 4 times, most recently from 6bd931d to 2d31df2 Compare June 28, 2017 17:12
@allisonwang allisonwang changed the title [AIRFLOW-1332][WIP] Split logs based on try number [AIRFLOW-1332] Split logs based on try number Jun 28, 2017
@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch 3 times, most recently from a1abe58 to bb7ee73 Compare June 29, 2017 03:58
Comment thread airflow/bin/cli.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Session is used below on line 385, you can reuse this new one there.

Comment thread airflow/bin/cli.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Lines 404/405 already get the TI from the DB, and I think we can just reuse that. If you look at what refresh_from_db() is doing, it doesn't actually need the task to be parsed from the dagbag. We can probably move the logic from line 404/405 up here (the part that doesn't require parsing the DAGBag), and then we wouldn't need this additional query.

Reading the try number and then writing it back should be an atomic operation, otherwise two workers could get the same task instance and increment the try number twice (even though only one of them would actually run the task). refresh_from_db() does this with the lock_for_update param so you can take a look at that as an example if you don't end up rewriting the code to just use it in the first place.

Comment thread airflow/bin/cli.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's factor the logic for getting this path out somewhere, it's used in a couple of places. That includes the isoformat() part and probably the log_base part too.

Comment thread airflow/bin/cli.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's put dag at the start everywhere it appears in methods like this that you changed (it's the "highest level" param). Wait why do we need dag as a param actually, wouldn't dag just be self inside the clear function?

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What about the case where users upgrade from an old version of Airflow where max tries is not stored in the DB and try number might have been reset to 1 because of clearing via the UI?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

hmm not sure how users will be affected?

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Discussed offline, we are going to try to parse the DAG in the migration and set max_attempts based on the value in the DAG file.

Comment thread airflow/www/views.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cleaner is:
[''] * try_number

Comment thread airflow/www/views.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does this work as expected there is currently a running task that is not the first try that is writing to local disk and hasn't written to AWS yet? Seems like this would fail reading the last try number and not set remote_log_loaded to True when it should have.

Comment thread tests/models.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's break this set of asserts out into separate tests (they can share the setup steps if necessary by factoring them out). If all the asserts are clumped together the disadvantage is that the first failing assert will end the test case so the others won't be tested in that run.

Comment thread airflow/www/views.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: A little bit cleaner is
for remote_log, i in enumerate(remote_logs): (and then use remote_log instead of remote_logs[i] below)

Comment thread airflow/www/views.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Doesn't the page need to know which try # it is serving (assuming that the active tab is highlighted in the UI somehow).

@aoen

aoen commented Jun 29, 2017

Copy link
Copy Markdown
Contributor

Is the code quality decrease in the landscape results a false positive?

@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch 5 times, most recently from 379d74a to 0af21a0 Compare June 29, 2017 23:22
@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch from 0af21a0 to 1e90062 Compare June 29, 2017 23:47
Comment thread airflow/models.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I still feel like these exceptions are too broad. Can we use if conditions instead? e.g. if dag == None?

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

get_task will throw AirflowException when task_id is not found so I guess catching all exceptions at once is cleaner. We could case on the conditions but all of them will use the same way to handle those conditions as line 127.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You can use the methods that get_task uses internally instead to avoid having to deal with exceptions:
if dag_id not in dagbag.dags:
if not dag.has_task(task_id):

Might be good to factor these into a new method task.exists if you think it makes sense.

Comment thread tests/utils/test_dates.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's break these asserts into individual tests.

Comment thread airflow/utils/dates.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's add proper pydoc even though some of the other functions in this class do not have it.

@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch 2 times, most recently from 657dfeb to 0b75dba Compare July 11, 2017 20:28
@codecov-io

codecov-io commented Jul 11, 2017

Copy link
Copy Markdown

Codecov Report

Merging #2383 into master will decrease coverage by 0.05%.
The diff coverage is 37.81%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master    #2383      +/-   ##
==========================================
- Coverage    69.4%   69.34%   -0.06%     
==========================================
  Files         146      146              
  Lines       11289    11331      +42     
==========================================
+ Hits         7835     7858      +23     
- Misses       3454     3473      +19
Impacted Files Coverage Δ
airflow/www/views.py 66.99% <10.34%> (-0.64%) ⬇️
airflow/models.py 87.32% <100%> (+0.08%) ⬆️
airflow/utils/logging.py 31.62% <48.14%> (+4.95%) ⬆️
airflow/bin/cli.py 52.39% <61.9%> (+0.53%) ⬆️
airflow/utils/state.py 96.66% <0%> (+10%) ⬆️

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 3927723...be921c0. Read the comment docs.

@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch 4 times, most recently from b690bc0 to cc63759 Compare July 17, 2017 18:38
Comment thread airflow/models.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Couldn't dag be None (otherwise why check "if not dag" above)? If so dag.get_task will fail. Would be good to write a test for this too.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if dag is None it will fall into the first if branch? Will add more tests here.

Comment thread airflow/models.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: typo and also "for next" should be "for the next"

Comment thread airflow/models.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: s/total_try/max_tries (or at least total_tries)

Comment thread airflow/utils/logging.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nit: s/exist/exists

Comment thread airflow/utils/logging.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would be good to name this something a bit more descriptive:
def log_exists(self, log_location)

Comment thread airflow/utils/logging.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would be good to name this something a bit more descriptive:
def log_exists(self, log_location)

Comment thread airflow/utils/logging.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Typo

Comment thread airflow/utils/logging.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

:return: True if location exists else False

Comment thread airflow/www/views.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would be good to link to something here (if we don't have a design doc skeleton yet then we can just use the refactor PR with Bolke).

Comment thread airflow/www/views.py Outdated

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the logs should be in s3 here at this point of the code though right? Falling back to non-local logs might not be great, i.e. if logs should have come from a remote location and the logs don't exist there we shouldn't hide that error by showing the local logs.

@allisonwang allisonwang Jul 17, 2017

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Exactly so I removed the surface_error flag and changed return_error to True when reading the remote logs.

@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch from cc63759 to d121f55 Compare July 17, 2017 22:24
@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch from d121f55 to 969f416 Compare July 19, 2017 18:00
Comment thread airflow/bin/cli.py
settings.configure_vars()
settings.configure_orm()

if not args.pickle and not dag:

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we should use is not None for these

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

o nvm if it's a refactor

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@saguziel Just wondering why checking is not None is better? Isn't it redundant in this case?

Comment thread airflow/bin/cli.py

if not args.pickle and not dag:
dag = get_dag(args)
elif not dag:

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

same as above

@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch from d0a2548 to 7cc8a53 Compare July 21, 2017 00:04
@allisonwang
allisonwang force-pushed the allison--add-task-attempt branch from 7cc8a53 to be921c0 Compare July 21, 2017 00:27
@aoen

aoen commented Jul 21, 2017

Copy link
Copy Markdown
Contributor

LGTM

@aoen

aoen commented Jul 21, 2017

Copy link
Copy Markdown
Contributor

def _get_log(self, ti, log_filename):
Unused argument 'ti'

@asfgit asfgit closed this in b49986c Jul 21, 2017
@bolkedebruin

Copy link
Copy Markdown
Contributor

@aoen I'm a bit surprised why this was merged. I my opinion the refactor Allison is doing should have been the one going in and it will soon. This one just creates new legacy and should not arrive in any release. What was the rush? If it was really needed you could have just used it in a local build?

Moreover it does not keep to the commit guidelines. With such a big change that really isn't nice.

@aoen

aoen commented Jul 21, 2017

Copy link
Copy Markdown
Contributor

@bolkedebruin I mentioned in the other thread (logging refactor) that I would be merging this one, and didn't get any -1s so I went ahead:

There is still a lot of work left here so we are going to spend a bit more time flushing out a design
doc for Airflow logging, and merge the initial change that we initially though should be blocked by this one: #2383 (comment) . The reason being that although the PR above does make logging a little bit messier, it makes the semantics of a logfile a lot more reasonable so it is still a net win. We will continue to iterate on the Airflow logging design in parallel.
By messier I am referring to the other PR I referenced (#2383 (comment)), we are going to merge that as is without blocking on this PR while continuing on this PR in parallel.

With respect to the urgency, while there is definitely risk that we will not be able to complete the logging in time, and certainly not in time to test/merge/release Allison's change internally at Airbnb, I still think that saner semantics/log file separation is worth it. If the choice was between merging neither PR or just this one, I believe Airflow is better off with this one merged.

By not following the commit guidelines do you mean the missing - between Airflow and the jira number?

@bolkedebruin

Copy link
Copy Markdown
Contributor

Ok I don't know if I agree with your assessment Airflow is better off this way. I wouldn't be very happy to have this in a release. But given the progress Allison is making with the other PR, one that I am willing to test, lets agree to disagree and help Allison as much as we can.

Concerning this PR I though it existed of two commits, but you probably squashed them. The '-' is minor. The description isn't really what/why, but more concerning is the lack of a documentation update as it does change things operationally. This can catch people by surprise as has happened with logging before.

@aoen

aoen commented Jul 21, 2017

Copy link
Copy Markdown
Contributor

Ok I don't know if I agree with your assessment Airflow is better off this way. I wouldn't be very happy to have this in a release. But given the progress Allison is making with the other PR, one that I am willing to test, lets agree to disagree and help Allison as much as we can.

I am happy to start a vote or discuss further with you via video chat if you feel it is important, please let me know. I believe pretty strongly in this change, but we should keep things democratic, and can revert the change based on the vote result. FWIW I did run this by Max early on, and he agreed with the change. In addition we created a thread in the mailing list to discuss these changes and hear people's concerns (though albeit not the slightly more complex logic that would be required on the logging side) since it was a decently-sized changed to the core.

Concerning this PR I though it existed of two commits, but you probably squashed them.

I think we should follow 1 commit to 1 PR as much as possible on master to keep history linear and sane (and so that the JIRA tags will be unique and match correctly). I also think that 1 commit was a reasonable granularity for this change. The reason I asked Allison to create a separate commit instead of force pushing was so that it would be easy for me to safely review the changes from the 1st commit to the 2nd commit (really the 2nd commit was just bug fixes on the first one).

The description isn't really what/why, but more concerning is the lack of a documentation update as it does change things operationally. This can catch people by surprise as has happened with logging before.

This is definitely true, I was operating on the precedent of previous logging changes not being communicated, but I agree this is not a good excuse. I have asked Allison to create a follow-up PR to add some additional details to the log section of the configuration.rst document. If there are additional kinds of communication you think are warranted please let me know.

@bolkedebruin

Copy link
Copy Markdown
Contributor

@aoen No need to vote. Your judgement is as good as mine. I'm not happy with it, but the right fix, imho, is in progress. Let's work together on getting that one in.

On the PR squashing: I overlooked your squash that is what I meant to say. So the 'merge' was fine. Just some details with the PR itself that weren't as nice.

asfgit pushed a commit that referenced this pull request Aug 9, 2017
This PR updates Airflow configuration
documentations to include a recent change to split
task logs by try number #2383.

Closes #2467 from AllisonWang/allison--update-doc
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

5 participants