Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add logging #99

Merged
merged 16 commits into from
Apr 29, 2014
Merged

Add logging #99

merged 16 commits into from
Apr 29, 2014

Conversation

davetron5000
Copy link
Contributor

Per the discussion in #97, this adds a log of logging to what's going on. It does so in a conservative way, in that no behavior will change without taking extra steps. Will comment on a few specific things in the pull request.

I like gemsets, but that doesn't mean anyone else should...
# message:: message to log
# args:: args of the resque job in context
# exception:: the exception that might be causing a retry
def log(message, args, exception=nil)
Copy link
Contributor Author

Choose a reason for hiding this comment

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

A few notes about this:

  • I didn't want to include Resque::Logging as a) we don't need the different severity levels and b) those method names are super-common and would squash any jobs that do something similar (like my jobs :)
  • Checking for Resque.logger is mirroring what's in Resque::Worker - presumably there is a good reason, but I guess generally logging should not take down your system
  • The environment variable is there so that a released version of this library would behave the same way, just in case the addition of logging causes some problem. This means people can opt-in, and they can opt-in on a per-worker basis, which seems handy. The value of "true" is debatable. I prefer it, since ENV can only store strings, but I know some people like 1. If someone feel strongly, we can change it.

@davetron5000
Copy link
Contributor Author

I think I fixed all the invocation syntax locations (at least according to my greps :)

@davetron5000
Copy link
Contributor Author

OK, I'm gonna wait for a few minutes before sending up diffs while you are still commenting. I realize that is making things confusing.

@@ -12,3 +12,5 @@ stdout
tags
tags.*
*.gem
.ruby-version
Copy link
Collaborator

Choose a reason for hiding this comment

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

Thank you!

@jzaleski
Copy link
Collaborator

@davetron5000 sorry for the litany of comments/requests. I think we're really close now. Please give it a once over and let's get this merged!

@lantins
Copy link
Owner

lantins commented Apr 25, 2014

Trying to get caught up here and not entirely sure I follow.

Did you decide to go with a specific RESQUE_RETRY_LOGGING or just use VVERBOSE?

@@ -40,6 +46,8 @@ def save
}

Resque.redis.setex(failure_key, 2*retry_delay, Resque.encode(data))
else
log "retry_delay: #{retry_delay} <= 0 - ignoring", payload, exception
Copy link
Contributor Author

Choose a reason for hiding this comment

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

Again, not sure if this captures the intent of doing nothing for this case. Obviously I can use this message to see what happened, but if there's a better way to state what this case is please let me know and I can make a better log message

@davetron5000
Copy link
Contributor Author

Even if there are no further code review comments, I'd like to wait on this until I've run it in production with the new changes I added.

@davetron5000
Copy link
Contributor Author

Did you decide to go with a specific RESQUE_RETRY_LOGGING or just use VVERBOSE?

@jzaleski suggested to just remove the extra env var and allow VVERBOSE to trigger it, which is fine with me. I was just being extra cautious. Happy to add it back if you convince him otherwise :)

@jzaleski
Copy link
Collaborator

@lantins we decided to remove the additional environment variable and rely on "VERBOSE" and "VVERBOSE" that way anyone using the plugin will get it for free when either of the env-vars is set.

Thisi makes our logging totally independent of whatever logging methods
are provided by Resque.  We use Resque.logger underneath, but the plugin
log statements now go through on interface that we control
The log message in question needs to distinguish between "job is not
retriable" and "job IS retriable, but isn't actually being retried right
now".

We also don't want to go to Redis more than is required, so intermediate
variables to the rescue.  Also happens to straighten out that
double-negative, DeMorgan's Law-requiring `if` statement expression.
@@ -82,6 +93,10 @@ def retrying?
def cleanup_retry_failure_log!
Resque.redis.del(failure_key) if retryable?
end

def args_from(payload)
Copy link
Contributor Author

Choose a reason for hiding this comment

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

Just being super paranoid about what's in payload - log messages shouldn't crash the system

Copy link
Collaborator

Choose a reason for hiding this comment

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

That's a good idea. Thank you

@davetron5000
Copy link
Contributor Author

This has been running in production for me for several days without incident and helped me figure out #97. I'm good with this if everyone else is, but still willing to make whatever other changes we want.

@lantins
Copy link
Owner

lantins commented Apr 28, 2014

I've not fully reviewed it as @jzaleski seems to be on the case and I've had some other things to deal with!

Will be happy to see it in a new release, thanks for reporting back @davetron5000 :)

module Plugins
module Retry
module Logging
# Log messages through the Resque logger. Generally not for appication
Copy link
Collaborator

Choose a reason for hiding this comment

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

Very minor change.. "application" is spelled incorrectly here.

@jzaleski
Copy link
Collaborator

@davetron5000 you did a great job on this! Thank you very much for your patience. Just a couple more minor cosmetic things to do to get this one over the finish line.

As soon as this is in I plan to revisit #97

Thank you for all the hard work!

Also, if possible, please see if you can get this ready to auto-merge.. If you have any difficulty I will handle it from the command-line. Thanks!

@davetron5000
Copy link
Contributor Author

Cool. Made those two changes.

I'm not sure why it's not showing the Big Green Merge Button™—I fetched the latest from this repo and a merge gives me "Already up-to-date". Maybe something got borked cross-repo? I usually do this from within a repo where I can commit…

@jzaleski
Copy link
Collaborator

Try this:

  • git remote add upstream [email protected]:lantins/resque-retry.git
  • git fetch --all
  • git merge upstream/master

Resolve any conflicts and repush

@davetron5000
Copy link
Contributor Author

Despite having fetched this repo, I was typing git merge origin/master o_O. Should hopefully be good now…

@jzaleski
Copy link
Collaborator

Looks great @davetron5000. Travis just passed.. Merging!

jzaleski added a commit that referenced this pull request Apr 29, 2014
@jzaleski jzaleski merged commit 700dcf5 into lantins:master Apr 29, 2014
lantins added a commit that referenced this pull request May 19, 2014
- Log to DEBUG rather then INFO level to reduce noise during operation.
- Adjust yardoc comment style to match other sections of the repo.
- Remove 1 level of indentation.

Ref: #99
lantins added a commit that referenced this pull request May 19, 2014
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.

3 participants