Skip to content

Log when enumerator has nothing to iterate#49

Merged
GustavoCaso merged 1 commit into
masterfrom
add_logging_when_nothing_to_iterate
Mar 19, 2020
Merged

Log when enumerator has nothing to iterate#49
GustavoCaso merged 1 commit into
masterfrom
add_logging_when_nothing_to_iterate

Conversation

@djmortonShopify

Copy link
Copy Markdown
Contributor

If an Enumerator is built and has nothing to iterate, it can be confusing for developers. This is particularly true with ActiveRecord enumerators, where developers can be tripped up by default scopes excluding records they don't realize will be excluded. This PR adds a log message if we attempt to iterate an enumerator with no records to hopefully hint to developers that their enumerator did not actually return anything to help them pinpoint the source of their problem.

Comment thread test/unit/active_job_iteration_test.rb Outdated
assert_logged(%([JobIteration::Iteration] Enumerator found nothing to iterate!)) do
work_one_job
end

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

✂️

@moechaieb

Copy link
Copy Markdown

Thoughts on moving this one level up the stack and adding this logging to Iteration API so that we log when any enumerator is empty?

@GustavoCaso

GustavoCaso commented Mar 18, 2020

Copy link
Copy Markdown
Contributor

Thoughts on moving this one level up the stack and adding this logging to Iteration API so that we log when any enumerator is empty?

@moechaieb this as low as you can get, right? What do you mean with the Iteration API?

@djmortonShopify djmortonShopify force-pushed the add_logging_when_nothing_to_iterate branch from f4867e2 to e2ceb42 Compare March 18, 2020 20:43
@djmortonShopify

Copy link
Copy Markdown
Contributor Author

The ActiveRecord case is the one that seems to come up most often, but I'll look at moving it up and see if it makes sense.

@GustavoCaso GustavoCaso 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.

Awesome

@djmortonShopify

Copy link
Copy Markdown
Contributor Author

@moechaieb Sorry... my brain blanked there... My test is for activerecord enumerators, but the actual code is in iteration.rb and should handle all enumerators.

@GustavoCaso

GustavoCaso commented Mar 18, 2020

Copy link
Copy Markdown
Contributor

@moechaieb @djmortonShopify this change deal with all enumerators.

We first build_enumerator which is agnostic of the enumerator and then we iterate over it.

@djmortonShopify djmortonShopify force-pushed the add_logging_when_nothing_to_iterate branch from e2ceb42 to d2766e6 Compare March 18, 2020 20:50
@GustavoCaso GustavoCaso merged commit c45a892 into master Mar 19, 2020

logger.info(
"[JobIteration::Iteration] Enumerator found nothing to iterate! " \
"(times_interrupted: #{times_interrupted}, cursor_position: #{cursor_position})"

@kirs kirs Mar 19, 2020

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.

Why not use tagged logging like we do everywhere? E.g. times_interrupted=#{times_interrupted} cursor_position=#{cursor_position}?

They're easier to parse and Splunk matches them by default.

@kirs

kirs commented Mar 20, 2020

Copy link
Copy Markdown
Contributor

The version you guys pushed should solve the immediate problem. An alternative way that I thought of would be to count number of iterations that has been done in a run and always log that number, which would make the log output consistent (you'd see it with all jobs) and maybe help to debug some other problems in the future.

@sambostock sambostock deleted the add_logging_when_nothing_to_iterate branch February 6, 2024 15:21
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.

4 participants