added more level 3 logging using a custom telemetry plugin, which is internal use only

this will therefore not be documented.
This commit is contained in:
HoneyryderChuck 2021-02-12 10:31:03 +00:00
parent bfe77fe92c
commit ad88aa27cf
4 changed files with 103 additions and 0 deletions

View File

@ -78,6 +78,10 @@ Style/TrailingUnderscoreVariable:
Style/AccessModifierDeclarations:
Enabled: false
Style/GlobalVars:
Exclude:
- lib/httpx/plugins/internal_telemetry.rb
Performance/TimesMap:
Enabled: false

View File

@ -268,6 +268,7 @@ module HTTPX
# dread
loop do
siz = @io.read(@window_size, @read_buffer)
log(level: 3, color: :cyan) { "IO READ: #{siz} bytes..." }
unless siz
ex = EOFError.new("descriptor closed")
ex.set_backtrace(caller)
@ -296,6 +297,7 @@ module HTTPX
end
siz = @io.write(@write_buffer)
log(level: 3, color: :cyan) { "IO WRITE: #{siz} bytes..." }
unless siz
ex = EOFError.new("descriptor closed")
ex.set_backtrace(caller)

View File

@ -0,0 +1,93 @@
# frozen_string_literal: true
module HTTPX
module Plugins
#
# The InternalTelemetry plugin is for internal use only. It is therefore undocumented, and
# its use is disencouraged, as API compatiblity will **not be guaranteed**.
#
# The gist of it is: when debug_level of logger is enabled to 3 or greater, considered internal-only
# supported log levels, it'll be loaded by default.
#
# Against a specific point of time, which will be by default the session initialization, but can be set
# by the end user in $http_init_time, different diff metrics can be shown. The "point of time" is calculated
# using the monotonic clock.
module InternalTelemetry
module TrackTimeMethods
private
def elapsed_time
yield
ensure
meter_elapsed_time("#{self.class.superclass}##{caller_locations(1, 1)[0].label}")
end
def meter_elapsed_time(label)
$http_init_time ||= Process.clock_gettime(Process::CLOCK_MONOTONIC, :millisecond)
prev_time = $http_init_time
after_time = Process.clock_gettime(Process::CLOCK_MONOTONIC, :millisecond)
# $http_init_time = after_time
elapsed = after_time - prev_time
warn(+"\e[31m" << "[ELAPSED TIME]: #{label}: #{elapsed} (ms)" << "\e[0m")
end
end
module InstanceMethods
def self.included(klass)
klass.prepend TrackTimeMethods
super
end
def initialize(*)
meter_elapsed_time("Session: initializing...")
super
meter_elapsed_time("Session: initialized!!!")
end
private
def build_requests(*)
elapsed_time { super }
end
def fetch_response(*)
response = super
meter_elapsed_time("Session -> response") if response
response
end
def close(*)
super
meter_elapsed_time("Session -> close")
end
end
module RequestMethods
def self.included(klass)
klass.prepend TrackTimeMethods
super
end
def transition(nextstate)
state = @state
super
meter_elapsed_time("Request[#{@verb} #{@uri}: #{state}] -> #{nextstate}") if nextstate == @state
end
end
module ConnectionMethods
def self.included(klass)
klass.prepend TrackTimeMethods
super
end
def transition(nextstate)
state = @state
super
meter_elapsed_time("Connection[#{@origin}]: #{state} -> #{nextstate}") if nextstate == @state
end
end
end
register_plugin :internal_telemetry, InternalTelemetry
end
end

View File

@ -277,5 +277,9 @@ module HTTPX
::HTTPX.send(:const_set, :Session, proxy_session.class)
end
if Session.default_options.debug_level > 2
proxy_session = plugin(:internal_telemetry)
::HTTPX.send(:remove_const, :Session)
::HTTPX.send(:const_set, :Session, proxy_session.class)
end
end