sharpetronics/stripe-ruby
1
0
Fork 0
mirror of https://github.com/stripe/stripe-ruby.git synced 2025-08-10 00:01:09 -04:00
Code Issues Projects Releases Wiki Activity

Correct behavior for error logging

Browse Source 
A few changes:

* Add a new `Util.log_error` method which will forward to the equivalent
  of `#error` on a logger.
* Move errors produced by `StripeClient` to use `Util.log_error`.
* Change standard stdout logging behavior to log to stderr in the case
  of `Util.log_error.
* Change `Stripe.log_level` values to be an enum in a similar fashion as
  the standard library's built in `Logger`.
This commit is contained in:
Brandur 2017-08-11 11:45:43 -07:00
parent cb111a8e74
commit 1ca67cb954
6 changed files with 107 additions and 27 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
README.md
View File

@ -150,7 +150,7 @@ There are a few options for enabling it:
2. Set `Stripe.log_level`:
``` ruby
Stripe.log_level = "info"
Stripe.log_level = Stripe::LEVEL_INFO
```
### Writing a Plugin

24
lib/stripe.rb
View File

@ -1,6 +1,7 @@
# Stripe Ruby bindings
# API spec at https://stripe.com/docs/api
require 'cgi'
require 'logger'
require 'openssl'
require 'rbconfig'
require 'set'
@ -145,13 +146,15 @@ module Stripe
end
end
LEVEL_DEBUG = "debug"
LEVEL_INFO = "info"
# map to the same values as the standard library's logger
LEVEL_DEBUG = Logger::DEBUG
LEVEL_ERROR = Logger::ERROR
LEVEL_INFO = Logger::INFO
# When set prompts the library to log some extra information to $stdout about
# what it's doing. For example, it'll produce information about requests,
# responses, and errors that are received. Valid log levels are `debug` and
# `info`, with `debug` being a little more verbose in places.
# When set prompts the library to log some extra information to $stdout and
# $stderr about what it's doing. For example, it'll produce information about
# requests, responses, and errors that are received. Valid log levels are
# `debug` and `info`, with `debug` being a little more verbose in places.
#
# Use of this configuration is only useful when `.logger` is _not_ set. When
# it is, the decision what levels to print is entirely deferred to the logger.
@ -160,7 +163,14 @@ module Stripe
end
def self.log_level=(val)
if val != nil && ![LEVEL_DEBUG, LEVEL_INFO].include?(val)
# Backwards compatibility for values that we briefly allowed
if val == "debug"
val = LEVEL_DEBUG
elsif val == "info"
val = LEVEL_INFO
end
if val != nil && ![LEVEL_DEBUG, LEVEL_ERROR, LEVEL_INFO].include?(val)
raise ArgumentError, "log_level should only be set to `nil`, `debug` or `info`"
end
@log_level = val

8
lib/stripe/stripe_client.rb
View File

@ -279,7 +279,7 @@ module Stripe
end
def specific_api_error(resp, error_data, context)
Util.log_info('Stripe API error',
Util.log_error('Stripe API error',
status: resp.http_status,
error_code: error_data['code'],
error_message: error_data['message'],
@ -336,7 +336,7 @@ module Stripe
def specific_oauth_error(resp, error_code, context)
description = resp.data[:error_description] || error_code
Util.log_info('Stripe OAuth error',
Util.log_error('Stripe OAuth error',
status: resp.http_status,
error_code: error_code,
error_description: description,
@ -364,7 +364,7 @@ module Stripe
end
def handle_network_error(e, context, num_retries, api_base=nil)
Util.log_info('Stripe OAuth error',
Util.log_error('Stripe network error',
error_message: e.message,
idempotency_key: context.idempotency_key,
request_id: context.request_id
@ -481,7 +481,7 @@ module Stripe
private :log_response
def log_response_error(context, request_start, e)
Util.log_info("Request error",
Util.log_error("Request error",
elapsed: Time.now - request_start,
error_message: e.message,
idempotency_key: context.idempotency_key,

39
lib/stripe/util.rb
View File

@ -89,10 +89,17 @@ module Stripe
end
end
def self.log_error(message, data = {})
if !Stripe.logger.nil? ||
!Stripe.log_level.nil? && Stripe.log_level <= Stripe::LEVEL_ERROR
log_internal(message, data, color: :cyan,
level: Stripe::LEVEL_ERROR, logger: Stripe.logger, out: $stderr)
end
end
def self.log_info(message, data = {})
if !Stripe.logger.nil? ||
Stripe.log_level == Stripe::LEVEL_DEBUG ||
Stripe.log_level == Stripe::LEVEL_INFO
!Stripe.log_level.nil? && Stripe.log_level <= Stripe::LEVEL_INFO
log_internal(message, data, color: :cyan,
level: Stripe::LEVEL_INFO, logger: Stripe.logger, out: $stdout)
end
@ -100,7 +107,7 @@ module Stripe
def self.log_debug(message, data = {})
if !Stripe.logger.nil? ||
Stripe.log_level == Stripe::LEVEL_DEBUG
!Stripe.log_level.nil? && Stripe.log_level <= Stripe::LEVEL_DEBUG
log_internal(message, data, color: :blue,
level: Stripe::LEVEL_DEBUG, logger: Stripe.logger, out: $stdout)
end
@ -341,6 +348,17 @@ module Stripe
end
private_class_method :colorize
# Turns an integer log level into a printable name.
def self.level_name(level)
case level
when LEVEL_DEBUG then "debug"
when LEVEL_ERROR then "error"
when LEVEL_INFO then "info"
else level
end
end
private_class_method :level_name
# TODO: Make these named required arguments when we drop support for Ruby
# 2.0.
def self.log_internal(message, data = {}, color: nil, level: nil, logger: nil, out: nil)
@ -353,19 +371,16 @@ module Stripe
}.join(" ")
if !logger.nil?
str = "message=%s %s" % [wrap_logfmt_value(message), data_str]
case level
when Stripe::LEVEL_DEBUG
logger.debug(str)
else # Stripe::LEVEL_INFO (there should be no other values)
logger.info(str)
end
# the library's log levels are mapped to the same values as the
# standard library's logger
logger.log(level,
"message=%s %s" % [wrap_logfmt_value(message), data_str])
elsif out.isatty
out.puts "%s %s %s" %
[colorize(level[0, 4].upcase, color, out.isatty), message, data_str]
[colorize(level_name(level)[0, 4].upcase, color, out.isatty), message, data_str]
else
out.puts "message=%s level=%s %s" %
[wrap_logfmt_value(message), level, data_str]
[wrap_logfmt_value(message), level_name(level), data_str]
end
end
private_class_method :log_internal

4
test/stripe/stripe_client_test.rb
View File

@ -240,7 +240,7 @@ module Stripe
param: 'param',
type: 'type',
}
Util.expects(:log_info).with('Stripe API error',
Util.expects(:log_error).with('Stripe API error',
status: 500,
error_code: error['code'],
error_message: error['message'],
@ -282,7 +282,7 @@ module Stripe
status: 400
)
Util.expects(:log_info).with('Stripe OAuth error',
Util.expects(:log_error).with('Stripe OAuth error',
status: 400,
error_code: "invalid_request",
error_description: "No grant type specified",

57
test/stripe/util_test.rb
View File

@ -1,4 +1,3 @@
require "logger"
require File.expand_path('../../test_helper', __FILE__)
module Stripe
@ -169,12 +168,16 @@ module Stripe
@old_log_level = Stripe.log_level
Stripe.log_level = nil
@old_stderr = $stderr
$stderr = StringIO.new
@old_stdout = $stdout
$stdout = StringIO.new
end
teardown do
Stripe.log_level = @old_log_level
$stderr = @old_stderr
$stdout = @old_stdout
end
@ -190,6 +193,12 @@ module Stripe
assert_equal "message=foo level=debug \n", $stdout.string
end
should "not log if level set to error" do
Stripe.log_level = Stripe::LEVEL_ERROR
Util.log_debug("foo")
assert_equal "", $stdout.string
end
should "not log if level set to info" do
Stripe.log_level = Stripe::LEVEL_INFO
Util.log_debug("foo")
@ -197,6 +206,31 @@ module Stripe
end
end
context ".log_error" do
should "not log if logging is disabled" do
Util.log_error("foo")
assert_equal "", $stdout.string
end
should "log if level set to debug" do
Stripe.log_level = Stripe::LEVEL_DEBUG
Util.log_error("foo")
assert_equal "message=foo level=error \n", $stderr.string
end
should "log if level set to error" do
Stripe.log_level = Stripe::LEVEL_ERROR
Util.log_error("foo")
assert_equal "message=foo level=error \n", $stderr.string
end
should "log if level set to info" do
Stripe.log_level = Stripe::LEVEL_INFO
Util.log_error("foo")
assert_equal "message=foo level=error \n", $stderr.string
end
end
context ".log_info" do
should "not log if logging is disabled" do
Util.log_info("foo")
@ -209,6 +243,12 @@ module Stripe
assert_equal "message=foo level=info \n", $stdout.string
end
should "not log if level set to error" do
Stripe.log_level = Stripe::LEVEL_ERROR
Util.log_debug("foo")
assert_equal "", $stdout.string
end
should "log if level set to info" do
Stripe.log_level = Stripe::LEVEL_INFO
Util.log_info("foo")
@ -238,6 +278,13 @@ module Stripe
end
end
context ".log_error" do
should "log to the logger" do
Util.log_error("foo")
assert_equal "message=foo ", @out.string
end
end
context ".log_info" do
should "log to the logger" do
Util.log_info("foo")
@ -285,6 +332,14 @@ module Stripe
end
end
context ".level_name" do
should "convert levels to names" do
assert_equal "debug", Util.send(:level_name, LEVEL_DEBUG)
assert_equal "error", Util.send(:level_name, LEVEL_ERROR)
assert_equal "info", Util.send(:level_name, LEVEL_INFO)
end
end
context ".log_internal" do
should "log in a terminal friendly way" do
out = StringIO.new