diff --git a/.rubocop.yml b/.rubocop.yml new file mode 100644 index 0000000..63b7ceb --- /dev/null +++ b/.rubocop.yml @@ -0,0 +1,131 @@ +# Commonly used screens these days easily fit more than 80 characters. +Metrics/LineLength: + Max: 120 + +# Too short methods lead to extraction of single-use methods, which can make +# the code easier to read (by naming things), but can also clutter the class +Metrics/MethodLength: + Max: 100 + +# The guiding principle of classes is SRP, SRP can't be accurately measured by LoC +Metrics/ClassLength: + Max: 1500 + +Metrics/AbcSize: + Max: 40 + +Metrics/CyclomaticComplexity: + Max: 40 + +Metrics/PerceivedComplexity: + Max: 40 + +# No space makes the method definition shorter and differentiates +# from a regular assignment. + +Layout/AccessModifierIndentation: + Enabled: true + IndentationWidth: 4 + +# Single quotes being faster is hardly measurable and only affects parse time. +# Enforcing double quotes reduces the times where you need to change them +# when introducing an interpolation. Use single quotes only if their semantics +# are needed. +Style/StringLiterals: + EnforcedStyle: double_quotes + +# We do not need to support Ruby 1.9, so this is good to use. +Style/SymbolArray: + Enabled: true + +# Mixing the styles looks just silly. +Style/HashSyntax: + EnforcedStyle: ruby19_no_mixed_keys + +# has_key? and has_value? are far more readable than key? and value? +Style/PreferredHashMethods: + Enabled: false + +# String#% is by far the least verbose and only object oriented variant. +Style/FormatString: + EnforcedStyle: percent + +Style/CollectionMethods: + Enabled: true + PreferredMethods: + # inject seems more common in the community. + reduce: "inject" + +Style/UnneededInterpolation: + Enabled: flase + +Style/RescueStandardError: + Enabled: flase + +# Either allow this style or don't. Marking it as safe with parenthesis +# is silly. Let's try to live without them for now. +Style/ParenthesesAroundCondition: + AllowSafeAssignment: false +Lint/AssignmentInCondition: + AllowSafeAssignment: false + +# A specialized exception class will take one or more arguments and construct the message from it. +# So both variants make sense. +Style/RaiseArgs: + Enabled: false + +# Fail is an alias of raise. Avoid aliases, it's more cognitive load for no gain. +# The argument that fail should be used to abort the program is wrong too, +# there's Kernel#abort for that. +Style/SignalException: + EnforcedStyle: only_raise + +# Suppressing exceptions can be perfectly fine, and be it to avoid to +# explicitly type nil into the rescue since that's what you want to return, +# or suppressing LoadError for optional dependencies +Lint/HandleExceptions: + Enabled: false + +# { ... } for multi-line blocks is okay, follow Weirichs rule instead: +# https://web.archive.org/web/20140221124509/http://onestepback.org/index.cgi/Tech/Ruby/BraceVsDoEnd.rdoc +Style/BlockDelimiters: + Enabled: false + +# do / end blocks should be used for side effects, +# methods that run a block for side effects and have +# a useful return value are rare, assign the return +# value to a local variable for those cases. +Style/MethodCalledOnDoEndBlock: + Enabled: true + +# Enforcing the names of variables? To single letter ones? Just no. +Style/SingleLineBlockParams: + Enabled: false + +# Shadowing outer local variables with block parameters is often useful +# to not reinvent a new name for the same thing, it highlights the relation +# between the outer variable and the parameter. The cases where it's actually +# confusing are rare, and usually bad for other reasons already, for example +# because the method is too long. +Lint/ShadowingOuterLocalVariable: + Enabled: false + +# Check with yard instead. +Style/Documentation: + Enabled: false + +# This is just silly. Calling the argument `other` in all cases makes no sense. +Naming/BinaryOperatorParameterName: + Enabled: false + +# There are valid cases, for example debugging Cucumber steps, +# also they'll fail CI anyway +Lint/Debugger: + Enabled: false + +# Style preference +Style/MethodDefParentheses: + Enabled: false + +Style/TrailingCommaInHashLiteral: + Enabled: false diff --git a/.ruby-version b/.ruby-version index ccbccc3..24ba9a3 100644 --- a/.ruby-version +++ b/.ruby-version @@ -1 +1 @@ -2.2.0 +2.7.0 diff --git a/lib/logdna.rb b/lib/logdna.rb index 8372a1a..a3351cd 100755 --- a/lib/logdna.rb +++ b/lib/logdna.rb @@ -1,10 +1,12 @@ #!/usr/bin/env ruby -# encoding: utf-8 +# frozen_string_literal: true + # require 'singleton' -require 'socket' -require 'uri' -require_relative 'logdna/client.rb' -require_relative 'logdna/resources.rb' +require "socket" +require "uri" +require_relative "logdna/client.rb" +require_relative "logdna/resources.rb" +require_relative "logdna/version.rb" module Logdna class ValidURLRequired < ArgumentError; end class MaxLengthExceeded < ArgumentError; end @@ -15,54 +17,28 @@ class Ruby < ::Logger Logger::TRACE = 5 attr_accessor :level, :app, :env, :meta - def initialize(key, opts={}) - @app = opts[:app] || 'default' - @level = opts[:level] || 'INFO' + def initialize(key, opts = {}) + @app = opts[:app] || "default" + @level = opts[:level] || "INFO" @env = opts[:env] @meta = opts[:meta] - @@client = nil unless defined? @@client - endpoint = opts[:endpoint] || Resources::ENDPOINT hostname = opts[:hostname] || Socket.gethostname - ip = opts.key?(:ip) ? "&ip=#{opts[:ip]}" : '' - mac = opts.key?(:mac) ? "&mac=#{opts[:mac]}" : '' - url = "#{endpoint}?hostname=#{hostname}#{mac}#{ip}" - begin - if (hostname.size > Resources::MAX_INPUT_LENGTH || @app.size > Resources::MAX_INPUT_LENGTH ) - raise MaxLengthExceeded.new - end - rescue MaxLengthExceeded => e + if hostname.size > Resources::MAX_INPUT_LENGTH || @app.size > Resources::MAX_INPUT_LENGTH puts "Hostname or Appname is over #{Resources::MAX_INPUT_LENGTH} characters" - handle_exception(e) - return - end - - begin - uri = URI(url) - rescue URI::ValidURIRequired => e - puts "Invalid URL Endpoint: #{url}" - handle_exception(e) return end - begin - request = Net::HTTP::Post.new(uri.request_uri, 'Content-Type' => 'application/json') - request.basic_auth 'username', key - request[:'user-agent'] = opts[:'user-agent'] || "ruby/#{LogDNA::VERSION}" - rescue => e - handle_exception(e) - return - end - - @@client = Logdna::Client.new(request, uri, opts) - end + ip = opts.key?(:ip) ? "&ip=#{opts[:ip]}" : "" + mac = opts.key?(:mac) ? "&mac=#{opts[:mac]}" : "" + url = "#{endpoint}?hostname=#{hostname}#{mac}#{ip}" + uri = URI(url) - def handle_exception(e) - exception_message = e.message - exception_backtrace = e.backtrace - # NOTE: should log with Ruby logger? - puts exception_message + request = Net::HTTP::Post.new(uri.request_uri, "Content-Type" => "application/json") + request.basic_auth("username", key) + request[:'user-agent'] = opts[:'user-agent'] || "ruby/#{LogDNA::VERSION}" + @client = Logdna::Client.new(request, uri, opts) end def default_opts @@ -83,77 +59,74 @@ def level=(value) @level = value end - def log(msg=nil, opts={}) - loggerExist? - message = msg - message = yield if msg.nil? && block_given? - @response = @@client.buffer(message, default_opts.merge(opts).merge({ - timestamp: (Time.now.to_f * 1000).to_i - })) - 'Saved' + def log(message = nil, opts = {}) + if message.nil? && block_given? + message = yield + end + if message.nil? + puts "provide either a message or block" + return + end + message = message.to_s.encode("UTF-8") + @client.write_to_buffer(message, default_opts.merge(opts).merge( + timestamp: (Time.now.to_f * 1000).to_i + )) end Resources::LOG_LEVELS.each do |lvl| name = lvl.downcase - define_method name do |msg=nil, opts={}, &block| - self.log(msg, opts.merge({ - level: lvl, - }), &block) + define_method name do |msg = nil, opts = {}, &block| + self.log(msg, opts.merge( + level: lvl + ), &block) end define_method "#{name}?" do - return Resources::LOG_LEVELS[self.level] == lvl if self.level.is_a? Numeric + return Resources::LOG_LEVELS[self.level] == lvl if level.is_a? Numeric + self.level == lvl end end def clear - @app = 'default' - @level = 'INFO' + @app = "default" + @level = "INFO" @env = nil @meta = nil end - def loggerExist? - if @@client.nil? - puts "Logger Not Initialized Yet" - close - end - end - - def <<(msg=nil, opts={}) - self.log(msg, opts.merge({ - level: '', - })) + def <<(msg = nil, opts = {}) + log(msg, opts.merge( + level: "" + )) end - def add(*arg) + def add(*_arg) puts "add not supported in LogDNA logger" - return false + false end - def unknown(msg=nil, opts={}) - self.log(msg, opts.merge({ - level: 'UNKNOWN', - })) + def unknown(msg = nil, opts = {}) + log(msg, opts.merge( + level: "UNKNOWN" + )) end - def datetime_format(*arg) + def datetime_format(*_arg) puts "datetime_format not supported in LogDNA logger" - return false + false end - def close - if defined? @@client and !@@client.nil? - @@client.exitout() + if !@client.nil? + @client.exitout end end at_exit do - if defined? @@client and !@@client.nil? - @@client.exitout() + if !@client.nil? + @client.exitout end end end diff --git a/lib/logdna/client.rb b/lib/logdna/client.rb index cd102b2..b26434e 100755 --- a/lib/logdna/client.rb +++ b/lib/logdna/client.rb @@ -1,47 +1,35 @@ -require 'net/http' -require 'socket' -require 'json' -require 'concurrent' -require 'thread' +# frozen_string_literal: true + +require "net/http" +require "socket" +require "json" +require "concurrent" +require "date" module Logdna class Client - def initialize(request, uri, opts) @uri = uri # NOTE: buffer is in memory - @buffer = StringIO.new - @messages = [] - @buffer_over_limit = false + @buffer = [] + @buffer_byte_size = 0 - @side_buffer = StringIO.new @side_messages = [] @lock = Mutex.new - @task = nil - - # NOTE: the byte limit only affects the message, not the entire message_hash - @actual_byte_limit = opts[:flushbyte] ||= Resources::FLUSH_BYTE_LIMIT - @actual_flush_interval = opts[:flushtime] ||= Resources::FLUSH_INTERVAL - - @@request = request - end - - def encode_message(msg) - msg = msg.to_s unless msg.instance_of? String - - begin - msg = msg.encode("UTF-8") - rescue Encoding::UndefinedConversionError => e - # NOTE: should this be raised or handled silently? - # raise e - end - msg + @side_message_lock = Mutex.new + @flush_limit = opts[:flush_size] || Resources::FLUSH_BYTE_LIMIT + @flush_interval = opts[:flush_interval] || Resources::FLUSH_INTERVAL + @flush_scheduled = false + @exception_flag = false + + @request = request + @retry_timeout = opts[:retry_timeout] || Resources::RETRY_TIMEOUT end - def message_hash(msg, opts={}) - obj = { + def process_message(msg, opts = {}) + processed_message = { line: msg, app: opts[:app], level: opts[:level], @@ -49,116 +37,98 @@ def message_hash(msg, opts={}) meta: opts[:meta], timestamp: Time.now.to_i, } - obj.delete(:meta) if obj[:meta].nil? - obj + processed_message.delete(:meta) if processed_message[:meta].nil? + processed_message end - def create_flush_task - return @task unless @task.nil? or !@task.running? - - t = Concurrent::TimerTask.new(execution_interval: @actual_flush_interval, timeout_interval: Resources::TIMER_OUT) do |task| - if @messages.any? - # keep running if there are queued messages, but don't flush - # because the buffer is being flushed due to being over the limit - unless @buffer_over_limit - flush() - end - else - # no messages means we can kill the task - task.kill - end - end - t.execute - end - - def check_side_buffer - return if @side_buffer.size == 0 - - @buffer.write(@side_buffer.string) - @side_buffer.truncate(0) - queued_side_messages = @side_messages - @side_messages = [] - queued_side_messages.each { |message_hash_obj| @messages.push(message_hash_obj) } + def schedule_flush + start_timer = lambda { + sleep(@exception_flag ? @retry_timeout : @flush_interval) + flush if @flush_scheduled + } + thread = Thread.new { start_timer } + thread.join end - - # this should always be running synchronously within this thread - def buffer(msg, opts) - buffer_size = write_to_buffer(msg, opts) - unless buffer_size.nil? - process_buffer(buffer_size) + def write_to_buffer(msg, opts) + if @lock.try_lock + processed_message = process_message(msg, opts) + new_message_size = processed_message.to_s.bytesize + @buffer.push(processed_message) + @buffer_byte_size += new_message_size + @flush_scheduled = true + @lock.unlock + + flush if @flush_limit <= @buffer_byte_size + schedule_flush unless @flush_scheduled + else + @side_message_lock.synchronize do + @side_messages.push(process_message(msg, opts)) + end end end - def write_to_buffer(msg, opts) - return if msg.nil? - msg = encode_message(msg) - - if @lock.locked? - @side_buffer.write(msg) - @side_messages.push(message_hash(msg, opts)) - return + # This method has to be called with @lock + def send_request + @side_message_lock.synchronize do + @buffer.concat(@side_messages) + @side_messages.clear end - check_side_buffer - buffer_size = @buffer.write(msg) - @messages.push(message_hash(msg, opts)) - buffer_size - end + @request.body = { + e: "ls", + ls: @buffer + }.to_json - def queue_to_buffer(queue=@queue) - next_object = queue.shift - write_to_buffer(next_object[:msg], next_object[:opts]) - end - - def process_buffer(buffer_size) - if buffer_size > @actual_byte_limit - @buffer_over_limit = true - flush() - @buffer_over_limit = false - else - @task = create_flush_task + handle_exception = lambda do |message| + puts message + @exception_flag = true + @side_message_lock.synchronize do + @side_messages.concat(@buffer) + end end - end - # this should be running synchronously if @buffer_over_limit i.e. called from self.buffer - # else asynchronously through @task - def flush() - if defined? @@request and !@@request.nil? - request_messages = [] - @lock.synchronize do - request_messages = @messages - @buffer.truncate(0) - @messages = [] + begin + @response = Net::HTTP.start( + @uri.hostname, + @uri.port, + use_ssl: @uri.scheme == "https" + ) do |http| + http.request(@request) end - return if request_messages.empty? - - real = { - e: 'ls', - ls: request_messages, - }.to_json - - @@request.body = real - @response = Net::HTTP.start(@uri.hostname, @uri.port, use_ssl: @uri.scheme == 'https') do |http| - http.request(@@request) + if @response.is_a?(Net::HTTPForbidden) + puts "Please provide a valid ingestion key" + elsif !@response.is_a?(Net::HTTPSuccess) + handle_exception.call("The response is not successful ") end + @exception_flag = false + rescue SocketError + handle_exception.call("Network connectivity issue") + rescue Errno::ECONNREFUSED => e + handle_exception.call("The server is down. #{e.message}") + rescue Timeout::Error => e + handle_exception.call("Timeout error occurred. #{e.message}") + ensure + @buffer.clear + end + end + + def flush - # don't kill @task if this was executed from self.buffer - # don't kill @task if there are queued messages - unless @buffer_over_limit || @messages.any? || @task.nil? - @task.shutdown - @task.kill + if @lock.try_lock + @flush_scheduled = false + if @buffer.any? || @side_messages.any? + send_request end + @lock.unlock + else + schedule_flush end end - def exitout() - check_side_buffer - if @messages.any? - flush() - end + def exitout + flush puts "Exiting LogDNA logger: Logging remaining messages" - return end end end diff --git a/lib/logdna/resources.rb b/lib/logdna/resources.rb index 66d6c16..b1323c4 100755 --- a/lib/logdna/resources.rb +++ b/lib/logdna/resources.rb @@ -6,8 +6,8 @@ module Resources MAX_REQUEST_TIMEOUT = 300000 MAX_LINE_LENGTH = 32000 MAX_INPUT_LENGTH = 80 + RETRY_TIMEOUT = 60 FLUSH_INTERVAL = 0.25 - TIMER_OUT = 15 FLUSH_BYTE_LIMIT = 500000 ENDPOINT = 'https://logs.logdna.com/logs/ingest'.freeze MAC_ADDR_CHECK = /^([0-9a-fA-F][0-9a-fA-F]:){5}([0-9a-fA-F][0-9a-fA-F])$/ diff --git a/logdna.gemspec b/logdna.gemspec index 89ebac0..1769c6e 100755 --- a/logdna.gemspec +++ b/logdna.gemspec @@ -20,7 +20,6 @@ Gem::Specification.new do |spec| spec.executables = spec.files.grep(%r{^exe/}) { |f| File.basename(f) } spec.require_paths = ['lib'] - spec.add_runtime_dependency 'concurrent-ruby', '~> 1.0' spec.add_runtime_dependency 'require_all', '~> 1.4' spec.add_runtime_dependency 'json', '~> 2.0' diff --git a/test.rb b/test.rb index 358082e..b554d4b 100644 --- a/test.rb +++ b/test.rb @@ -1,9 +1,7 @@ require 'require_all' require_all 'lib' - -options = {hostname: "new_ruby", meta:{:once => {:first => "nested1", :another => "nested2"}}} - +options = { hostname: "new_ruby", meta: { :once => { :first => "nested1", :another => "nested2" } } } logger1 = Logdna::Ruby.new('Your API Key', options) @@ -14,21 +12,18 @@ logger1.clear logger1.log('Is everything back to normal?') - logger1.log('Testing env app name change using log') logger1.env = 'PRODUCTION' logger1.app = 'CHANGED' logger1.log('This should be stage = PRODUCTION and appname = CHANGED') logger1.log('Testing env app name change using other messages') - -logger1.error('This is error message with env = DEVELOPMENT and appname = NIHAO', {:env => 'DEVELOPMENT', :app => 'NIHAO'}) +logger1.error('This is error message with env = DEVELOPMENT and appname = NIHAO', { :env => 'DEVELOPMENT', :app => 'NIHAO' }) logger1.log('Should not stay as DEVELOPMENT and NIHAO') logger1.env = 'DEVELOPMENT' logger1.app = 'NIHAO' logger1.log('Now should be DEVELOPMENT and NIHAO') -logger1.log('Logging metadata in trace level', {:meta => {:once => {:first => "nested1", :another => "nested2"}}, :level => "TRACE"}) - +logger1.log('Logging metadata in trace level', { :meta => { :once => { :first => "nested1", :another => "nested2" } }, :level => "TRACE" }) logger1.level = Logger::DEBUG logger1.log('This is debug message') @@ -38,7 +33,6 @@ logger1.level = Logger::WARN logger1.log('**************** This is the end of test ****************') - =begin logger1.level = Logger::WARN logger1.log('This should be warn') @@ -54,16 +48,9 @@ logger1.env = 'Staging' logger1.level = 'INFO' - - logger1.level = 'INFO' logger1.level == Logger::INFO - logger1.log('are changes all updated') =end sleep 3 - - - -