-
Notifications
You must be signed in to change notification settings - Fork 18
Optimize thread usage and handle http exceptions. #7
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
Conversation
smusali
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Let's try to make it consistent with Node.js Code Library regarding the configurable options...
dchai76
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is first pass, I haven't looked at the actual buffer logic yet. Main comments are:
- Indentation is inconsistent - can you fix that?
- It looks like there's at least one stray debug
puts, can you make sure there's nothing else extraneous? - I'm a little confused by the stuff you pulled out, mostly exception handling and cleanup logic. Can you explain why you did?
lib/logdna/client.rb
Outdated
| @actual_flush_interval = opts[:flushtime] ||= Resources::FLUSH_INTERVAL | ||
|
|
||
| @@request = request | ||
| @flush_limit = opts[:flush_size] ||= Resources::FLUSH_BYTE_LIMIT |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm pretty sure we're misusing ||= here. That operator sets the variable if it's falsy. So what we're doing here is setting opts[:flush_size] to Resources::FLUSH_BYTE_LIMIT if it's not already set, then setting @flush_limit to that value. I don't see the opts being used again, I think we just want to set @flush_limit, so @flush_limit = opts[:flush_size] || Resources::FLUSH_BYTE_LIMIT. Same below in line 22 and anywhere else we're using ||=.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
no it does assign the value to @flush_limit.
#a = 9
test = a ||= 1
puts test -> 1
a = 9
test = a ||= 1
puts test -> 9
lib/logdna/client.rb
Outdated
| else | ||
| # no messages means we can kill the task | ||
| task.kill | ||
| timer_task = Concurrent::TimerTask.new(execution_interval: @flush_interval, timeout_interval: Resources::TIMER_OUT) do |task| |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Indent is off here - it's 2 spaces everywhere else, 4 spaces here.
lib/logdna/client.rb
Outdated
| # no messages means we can kill the task | ||
| task.kill | ||
| timer_task = Concurrent::TimerTask.new(execution_interval: @flush_interval, timeout_interval: Resources::TIMER_OUT) do |task| | ||
| puts 'executing' |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This looks like a stray debug message?
lib/logdna/client.rb
Outdated
| write_to_buffer(next_object[:msg], next_object[:opts]) | ||
| end | ||
| if @lock.try_lock | ||
| if !@side_messages.empty? |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Same note about indent, it's inconsistent where you're using 2 or 4
lib/logdna/client.rb
Outdated
| begin | ||
| @lock.unlock | ||
| rescue | ||
| puts 'Nothing was locked' |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This seems not too useful
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
ok, I'll silent it
dchai76
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Not all of previous comments were addressed, and adding a few more.
lib/logdna/client.rb
Outdated
| def message_hash(msg, opts={}) | ||
| obj = { | ||
| def process_message(msg, opts={}) | ||
| processedMessage = { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Use underscores, please.
lib/logdna/client.rb
Outdated
| @task.shutdown | ||
| @task.kill | ||
| if(@response.is_a?(Net::HTTPForbidden)) | ||
| p "Please provide a valid ingestion key" |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Please be consistent and use puts everywhere
lib/logdna/client.rb
Outdated
| unless @buffer_over_limit || @messages.any? || @task.nil? | ||
| @task.shutdown | ||
| @task.kill | ||
| if(@response.is_a?(Net::HTTPForbidden)) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
(nit) Space after the if. This goes for everywhere in this block below.
lib/logdna.rb
Outdated
| return | ||
| end | ||
| request = Net::HTTP::Post.new(uri.request_uri, 'Content-Type' => 'application/json') | ||
| request.basic_auth('username', key) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Does this call possibly raise an exception? What should we do?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
no, it does not.
lib/logdna.rb
Outdated
| message = yield if msg.nil? && block_given? | ||
| @response = @@client.buffer(message, default_opts.merge(opts).merge({ | ||
| def log(message, opts={}) | ||
| if (message.length == 0) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Something like if (message.empty?) is more Ruby-ish.
lib/logdna.rb
Outdated
| end | ||
| message = message.to_s unless message.instance_of? String | ||
| message = message.encode("UTF-8") | ||
| @@client.write_to_buffer(message, default_opts.merge(opts).merge({ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There is no authorization.
I'm not following - previously if request.basic_auth failed, @@client could be nil. We're not checking for that failure anymore so I'm not sure what happens now.
lib/logdna/client.rb
Outdated
|
|
||
| def encode_message(msg) | ||
| msg = msg.to_s unless msg.instance_of? String | ||
| @flush_limit = opts[:flush_size] ? opts[:flush_size] : Resources::FLUSH_BYTE_LIMIT |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why did you change this format? @flush_limit = opts[:flush_size] || Resources::FLUSH_BYTE_LIMIT is more typical.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I thought this what you requested the last time.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I was requesting we use || instead of ||=.
lib/logdna.rb
Outdated
| return | ||
| end | ||
| request = Net::HTTP::Post.new(uri.request_uri, 'Content-Type' => 'application/json') | ||
| request.basic_auth('username', key) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
no, it does not.
lib/logdna.rb
Outdated
| end | ||
| message = message.to_s unless message.instance_of? String | ||
| message = message.encode("UTF-8") | ||
| @@client.write_to_buffer(message, default_opts.merge(opts).merge({ |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is the code library that writes a client that connects to our servers. Our servers use the ingestion keys for authenticating. (if a user has it, then he can send data to the server). Basic authentication does not make any sense here.
lib/logdna/client.rb
Outdated
|
|
||
| def encode_message(msg) | ||
| msg = msg.to_s unless msg.instance_of? String | ||
| @flush_limit = opts[:flush_size] ? opts[:flush_size] : Resources::FLUSH_BYTE_LIMIT |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I thought this what you requested the last time.
lib/logdna/client.rb
Outdated
| def encode_message(msg) | ||
| msg = msg.to_s unless msg.instance_of? String | ||
| @flush_limit = opts[:flush_size] ? opts[:flush_size] : Resources::FLUSH_BYTE_LIMIT | ||
| @flush_interval = opts[:flush_interval] ? opts[:flush_interval] : Resources::FLUSH_INTERVAL |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Same thing here, I think you mistook my request. Use || instead of ||=. That's the semantic intention.
lib/logdna/client.rb
Outdated
| end | ||
| msg | ||
| @request = request | ||
| @retry_timeout = opts[:retry_timeout] ? opts[:retry_timeout] : Resources::RETRY_TIMEOUT |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Same here.
lib/logdna/client.rb
Outdated
| flush if @buffer.any? || @side_messages.any? | ||
| puts "Exiting LogDNA logger: Logging remaining messages" | ||
| return | ||
| nil |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Just curious why you changed this, I feel like I see empty return more than an ending nil.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
because of linting ) but I can change its settings.
lib/logdna/client.rb
Outdated
| end | ||
|
|
||
| def exitout | ||
| flush if @buffer.any? || @side_messages.any? |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This test is already a part of flush so redundant; let's remove it and just let flush do it.
| def write_to_buffer(msg, opts) | ||
| return if msg.nil? | ||
| msg = encode_message(msg) | ||
| if @lock.try_lock |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
So the way the lock logic has changed makes me a bit nervous. Before we just wrapped in a synchronize block so we know we released in the right place. Now there's odd coordination going on, and I'm not sure it's correct, like you're releasing the lock before we flush (line 62) - is that right? If you're concerned about blocking what about just checking for if @lock.locked? and adding to @side_messages in that case, otherwise doing this logic in a synchronize block?
lib/logdna/client.rb
Outdated
| if @response.is_a?(Net::HTTPForbidden) | ||
| puts "Please provide a valid ingestion key" | ||
| elsif !@response.is_a?(Net::HTTPSuccess) | ||
| puts "The response is not successful " |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
No retry in this case?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
no, there is no point in retrying if the ingestion is not valid or not provided
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
But how do you know that that's why we didn't get a success response? What if there's some other error?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I know it does not look like an ideal handling. But testing how this mechanism works in Ruby, I found this to be the best approach. Because Ruby does not really work well with general exception handling. I tested it with writing just rescue, and switching off the connection and providing a bad ingestion key. The rescue part did not catch it. But it does catch if the specific exception names are defined. I can probably call handle_excpetion lambda in the second (!@response.is_a?(Net::HTTPSuccess)) condition.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This isn't an exception though, it's a non-success response. I'd consider a retry in this case - there's no harm.
lib/logdna/client.rb
Outdated
| @messages.push(message_hash(msg, opts)) | ||
| buffer_size | ||
| end | ||
| @lock.unlock if @lock.locked? |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
OK, having read through this all, I now see why you did the unlock here and to me that's an indication that the lock logic is not right - it really should be locked/unlocked in roughly the same block - there's a somewhat crazy coordination game going on right now that makes the logic unclear, and I think not quite right.
dchai76
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Just a comment on the yield block - let me review the lock logic tomorrow
lib/logdna.rb
Outdated
| self.log(msg, opts.merge({ | ||
| level: lvl, | ||
| }), &block) | ||
| define_method name do |msg = nil, opts = {}| |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
So this is the part I wanted you to understand. What this is (or was) doing is defining methods for each log level error', warn, debug, etc. And in doing so, it's mimicking the methods that the Ruby Logger has: https://ruby-doc.org/stdlib-2.4.0/libdoc/logger/rdoc/Logger.html#method-i-info. If you look at all of those methods (I linked to info, but it's there for all of them), you'll see that they all take a &blockthatEvaluates to the message to log.. You're removing the functionality by removing the block handling in log`. If you want to do that we can, but note that it does not deviate from what Ruby's Logger looks like.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The original code does not replicate the Ruby Logger behavior. I'll make a change so it will d replicate it
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Actually, it makes sense why the original code does not fully replicate the Ruby Logger behavior. I have restored it.
dchai76
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
It looks like you didn't finish addressing my previous comments but I did another round of review.
lib/logdna.rb
Outdated
| def log(message = nil, opts = {}) | ||
| if message.nil? && block_given? | ||
| message = yield | ||
| elsif message.nil? |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Might want to make this just if message.nil? to detect if the block provided is wrong.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
good point
lib/logdna.rb
Outdated
|
|
||
| define_method "#{name}?" do | ||
| return Resources::LOG_LEVELS[self.level] == lvl if self.level.is_a? Numeric | ||
| return Resources::LOG_LEVELS[level] == lvl if level.is_a? Numeric |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Did this work? I can't see where level is defined.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
it did work but I'll change to self.level. I did not notice it
lib/logdna.rb
Outdated
| if defined? @@client and !@@client.nil? | ||
| @@client.exitout() | ||
| end | ||
| @client.exitout if defined? @client && !@client.nil? |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Although optional, I prefer the style of always including parens on function calls for better readability.
lib/logdna.rb
Outdated
| if defined? @@client and !@@client.nil? | ||
| @@client.exitout() | ||
| end | ||
| def at_exit |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Wait, at_exit is something you should be calling - it's the block that executes on program exit - not something you should be defining. https://apidock.com/ruby/Kernel/at_exit
lib/logdna/client.rb
Outdated
| @@request.body = real | ||
| @response = Net::HTTP.start(@uri.hostname, @uri.port, use_ssl: @uri.scheme == 'https') do |http| | ||
| http.request(@@request) | ||
| handle_excpetion = lambda do |message| |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
You said done... you didn't fix the spelling here and in every reference. Please do.
lib/logdna/client.rb
Outdated
| def flush | ||
| if @lock.try_lock | ||
| @flush_scheduled = false | ||
| return if @buffer.empty? && @side_messages.empty? |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This seems wrong. You're returning without releasing the @lock. I think this could happen if 2 threads schedule a flush, one gets there first so empties the buffer/side_messages, then this thread gets here and never unlocks.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
good point. Thanks
lib/logdna/client.rb
Outdated
| if @response.is_a?(Net::HTTPForbidden) | ||
| puts "Please provide a valid ingestion key" | ||
| elsif !@response.is_a?(Net::HTTPSuccess) | ||
| puts "The response is not successful " |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This isn't an exception though, it's a non-success response. I'd consider a retry in this case - there's no harm.
logdna.gemspec
Outdated
| @@ -1,4 +1,5 @@ | |||
| # coding: utf-8 | |||
|
|
|||
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Prefer not having whitespace-only changes to files.
|
I think "enhancement" is the wrong label here. |
| return | ||
| def send_request | ||
| @side_message_lock.synchronize do | ||
| @buffer.concat(@side_messages) |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think we should leave a comment here that this function must be called with a claimed @lock (and/or even explicitly check for that in the code). Otherwise when I read this I'm confused why we're modifying @buffer without looking at @lock.
lib/logdna/client.rb
Outdated
| def flush | ||
| if @lock.try_lock | ||
| @flush_scheduled = false | ||
| if @buffer.empty? && @side_messages.empty? |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Alternatively, might want to reverse the logic so:
if @buffer.any? || @side_messages.any?
send_request
end
@lock.unlock
That way there's just a single @lock.unlock call.
dchai76
left a comment
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
OK! Let's make sure this gets good test coverage.
.gitignore
Outdated
| *.gem | ||
| .DS_Store | ||
| /bin/ | ||
| package-lock.json |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Ack no, this is back. Remove.
Most of the changes are in the client file. I removed the scheduling library bc it did not do the timing.
I also changed the names of some variable, which we will probably need to evert to the old ones if if we have a lot customer using this library.