Skip to content

Commit

Permalink
Restore (but deprecate) earlier logger API for now.
Browse files Browse the repository at this point in the history
  • Loading branch information
dazuma committed Dec 14, 2016
1 parent 488818b commit ab67f60
Show file tree
Hide file tree
Showing 4 changed files with 76 additions and 29 deletions.
63 changes: 53 additions & 10 deletions google-cloud-logging/lib/google/cloud/logging/logger.rb
Original file line number Diff line number Diff line change
Expand Up @@ -66,9 +66,15 @@ class Logger
attr_reader :labels

##
# A OrderedHash of Thread IDs to RequestInfo, keeping track of data
# associated with the request being handled by the current thread.
attr_reader :request_info
# A OrderedHash of Thread IDs to Stackdriver request trace ID. The
# Stackdriver trace ID is a shared request identifier across all
# Stackdriver services.
#
# @deprecated Use request_info
#
def trace_ids
@request_info.inject({}) { |r, (k, v)| r[k] = v.trace_id }
end

##
# Create a new Logger instance.
Expand Down Expand Up @@ -318,28 +324,65 @@ def level= severity
alias_method :sev_threshold=, :level=

##
# Associate request data with the current Thread
# Track a given trace_id by associating it with the current
# Thread
#
# @deprecated Use add_request_info
#
# @param [RequestInfo] info Info about the current request
def add_request_info info
request_info[current_thread_id] = info
def add_trace_id trace_id
add_request_id trace_id: trace_id
end

##
# Associate request data with the current Thread. You may provide
# either the individual pieces of data (trace ID, log name) or a
# populated RequestInfo object.
#
# @param [RequestInfo] info Info about the current request. Optional.
# If not present, a new RequestInfo is created using the remaining
# parameters.
# @param [String, nil] trace_id The trace ID, or `nil` if no trace ID
# should be logged.
# @param [String, nil] log_name The log name to use, or nil to use
# this logger's default.
#
def add_request_info info: nil,
trace_id: nil,
log_name: nil
info ||= RequestInfo.new trace_id, log_name
@request_info[current_thread_id] = info

# Start removing old entries if hash gets too large.
# This should never happen, because middleware should automatically
# remove entries when a request is finished
request_info.shift while request_info.size > 10_000
@request_info.shift while @request_info.size > 10_000

info
end

##
# Get the request data for the current Thread
#
# @return [RequestInfo, nil] The request data for the current thread,
# or `nil` if there is no data set.
#
def request_info
@request_info[current_thread_id]
end

##
# Untrack the RequestInfo that's associated with current Thread
#
# @return [RequestInfo] The info that's being deleted
#
def delete_request_info
request_info.delete current_thread_id
@request_info.delete current_thread_id
end

##
# @deprecated Use delete_request_info
alias_method :delete_trace_id, :delete_request_info

protected

##
Expand All @@ -354,7 +397,7 @@ def write_entry severity, message
# merge input labels and request info
merged_labels = {}
actual_log_name = log_name
info = request_info[current_thread_id]
info = request_info
if info
actual_log_name = info.log_name || actual_log_name
merged_labels["traceId"] = info.trace_id unless info.trace_id.nil?
Expand Down
21 changes: 12 additions & 9 deletions google-cloud-logging/lib/google/cloud/logging/middleware.rb
Original file line number Diff line number Diff line change
Expand Up @@ -63,8 +63,9 @@ def initialize app, logger: nil, log_name_map: DEFAULT_LOG_NAME_MAP
#
def call env
env["rack.logger"] = logger
request_info = get_request_info env
logger.add_request_info request_info
trace_id = get_trace_id env
log_name = get_log_name env
logger.add_request_info trace_id: trace_id, log_name: log_name
begin
@app.call env
ensure
Expand All @@ -73,23 +74,25 @@ def call env
end

##
# Extract data about this request as a RequestInfo.
# Determine the trace ID for this request.
#
# @private
# @param [Hash] env The Rack environment.
# @return [RequestInfo] The info.
def get_request_info env
# @return [String] The trace ID.
#
def get_trace_id env
trace_context = Stackdriver::Core::TraceContext.parse_rack_env env
trace_id = trace_context.trace_id
log_name = get_log_name env
Google::Cloud::Logging::Logger::RequestInfo.new trace_id, log_name
trace_context.trace_id
end

##
# Determine the log name override for this request, if any.
#
# @private
# @param [Hash] env The Rack environment.
# @return [String, nil] The log name override or nil if there is
# @return [String, nil] The log name override, or `nil` if there is
# no override.
#
def get_log_name env
return nil unless @log_name_map
path = "#{env['SCRIPT_NAME']}#{env['PATH_INFO']}"
Expand Down
15 changes: 8 additions & 7 deletions google-cloud-logging/test/google/cloud/logging/logger_test.rb
Original file line number Diff line number Diff line change
Expand Up @@ -122,8 +122,8 @@ def write_req_args severity, extra_labels: {}, log_name_override: nil
}

it "associates given info to current Thread ID" do
logger.add_request_info request_info
logger.request_info[Thread.current.object_id].must_equal request_info
logger.add_request_info info: request_info
logger.request_info.must_equal request_info
end

it "doesn't record more than 10_000 RequestInfo records" do
Expand All @@ -136,11 +136,12 @@ def write_req_args severity, extra_labels: {}, log_name_override: nil
# evaluate outside the block
logger.stub :current_thread_id, stubbed_thread_id do
10_001.times do
logger.add_request_info request_info
logger.add_request_info info: request_info
end
logger.request_info.size.must_equal 10_000
logger.request_info[first_thread_id].must_be_nil
logger.request_info[last_thread_id].must_equal request_info
request_info_hash = logger.instance_variable_get :@request_info
request_info_hash.size.must_equal 10_000
request_info_hash[first_thread_id].must_be_nil
request_info_hash[last_thread_id].must_equal request_info
end
end

Expand All @@ -153,7 +154,7 @@ def write_req_args severity, extra_labels: {}, log_name_override: nil

info = Google::Cloud::Logging::Logger::RequestInfo.new \
"my_trace_id", "my_app_log"
logger.add_request_info info
logger.add_request_info info: info

Time.stub :now, timestamp do
logger.error "Danger Will Robinson!"
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -56,9 +56,9 @@ def app.call(_) end
end

it "calls logger.add_request_info to track trace_id and log_name" do
stubbed_add_request_info = ->(this_request_info) {
this_request_info.trace_id.must_equal trace_id
this_request_info.log_name.must_equal "ruby_health_check_log"
stubbed_add_request_info = ->(args) {
args[:trace_id].must_equal trace_id
args[:log_name].must_equal "ruby_health_check_log"
}
logger.stub :add_request_info, stubbed_add_request_info do
middleware.call rack_env
Expand Down

1 comment on commit ab67f60

@blowmage
Copy link
Contributor

Choose a reason for hiding this comment

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

👍

Please sign in to comment.