Hi Brice,
Thanks for sending these patches, it's great stuff. I have some
general comments first, and then comments about each commit below:
GENERAL
* I noticed places where a monitor was being created lazily, e.g.
@last_logs ||= {}.extend(MonitorMixin). This is not thread safe, as
two threads could create and synchronize on different objects. To be
safe, I would create the last_logs hash in the initialize method or
include the MonitorMixin in your class.
* There are a couple of places where access to a hash is
synchronized, e.g. Instrumentation.listeners_of, but the hash is
returned from the method call. As a result a caller may be iterating
over it while another thread modifies it, resulting in undefined
behavior. It would be safer to return a dup'ed hash.
* Have you considered how inheritance will affect instrumented
methods? I wasn't able to produce a failure condition, but I'm
concerned about an infinite loop if a super and sub class instrument
the same method due to them both creating an "instrumented_method"
alias. You may want to make the instrumented method name unique, e.g
adding the klass object id to the method name?
COMMIT 1/8
lib/puppet/util/instrumentation.rb
* The unsubscribe method is never called as far as I can tell.
* The listeners_of method should return a dup of the @listeners_of
hash, otherwise, in the publish method, one thread could be iterating
though the hash, while another thread, e.g. rest, attempts to
concurrently modify it, e.g. saving a listener through the rest
interface causes the rehash method to be called.
* Related to this, if a listener has been notified, there's nothing
to prevent it from unsubscribing, or instrumenting additional methods
(from within its notify). I'm pretty sure bad-things-would-happen.
* The subscribe method registers listener.name, but the unsubscribe
uses listener.name.to_s
* rehash assumes that the caller is holding the monitor while it
clears the listeners_of hash. I'd recommend making it private.
lib/puppet/util/instrumentation/listener.rb
* Puppet.warnonce "Error during instrumentation notification: #{e}"
This should just be: warnonce(...)
spec/unit/util/instrumentation/listener_spec.rb
* This could use more tests, e.g. calling unsubscribe, without first
calling subscribe, calling subscribe multiple times, etc..
spec/unit/util/instrumentation_spec.rb
* This should also test that listeners are not notified when literal
and regex patterns don't match
-----------------------------------------------------
COMMIT 2/8
lib/puppet/indirector/instrumentation_data.rb
lib/puppet/indirector/instrumentation_data/local.rb
lib/puppet/indirector/instrumentation_data/rest.rb
lib/puppet/indirector/instrumentation_listener.rb
lib/puppet/indirector/instrumentation_listener/local.rb
lib/puppet/indirector/instrumentation_listener/rest.rb
lib/puppet/util/instrumentation/data.rb
* I had a lot of trouble getting this to work, partly because it's
new to me and also because of the whole plurality business. But we
could use better error messages. For example, when trying to search
for instrumentation data I tried the following
curl -k -H 'Accept: pson' -X GET "https://localhost:8140/production/
instrumentation_data/all"
Could not render to pson: undefined method `name' for nil:NilClass
I instead had to do ".../instrumentation_data_search/all"
* Also, if the listener does not provide data, e.g. process_name:
curl -k -H 'Accept: pson' -X GET "https://localhost:8140/production/
instrumentation_data/process_name"
Could not render to pson: undefined method `data' for
#<Puppet::Util::Instrumentation::Process_name:0x1024bca28>
* I'm seeing data leakage when "save"ing the listener
curl -k -H 'Accept: pson' -X PUT -H "Content-Type: text/pson" -d
"{\"document_type\":\"Puppet::Util::Instrumentation::Listener\",\"data
\":{\"enabled\":true,\"name\":\"log\"}}" "https://localhost:8140/
production/instrumentation_listener/log"
--- !ruby/object:Puppet::Util::Instrumentation::Listener
enabled: true
listener: !ruby/object:Puppet::Util::Instrumentation::Log
last_logs:
save_instrumentation_listener_local:
- save_instrumentation_listener_local took 0.000217
-----------------------------------------------------
COMMIT 3/8
lib/puppet/util/instrumentation/Instrumentable.rb
* The disable method does not restore the original method. The order
of the parameters to the alias_method needs to be reversed.
* Need to lowercase the filename
* Do the enable and disable methods really need to create local
variables, e.g. method = @method? We definitely don't need label and
data variables in the disable method.
spec/unit/util/instrumentation/instrumentable_spec.rb
* The spec should really call the various instrumented methods (as
opposed to seeing if they respond to) after the probe is enabled and
after it has been disabled, to ensure that the "disable" method really
works.
-----------------------------------------------------
COMMIT 4/8
lib/puppet/util/instrumentation/listeners/log.rb
* There's a race condition creating the @last_log object, which is
later used to synchronize on.
* The data method returns the actual last_logs array, not a dup, but
as the caller is iterating the array, another event could be
delivered. Note the :performance listener does perform a dup within a
synchronized block when returning its data.
spec/unit/util/instrumentation/listeners/log_spec.rb
* Dir.chdir(File.dirname(__FILE__)) { (s = lambda { |f| File.exist?
(f) ? require(f) : Dir.chdir("..") { s.call(f) } }).call("spec/
spec_helper.rb") }
can be changed to just:
require 'spec/spec_helper'
-----------------------------------------------------
COMMIT 5/8
lib/puppet/util/instrumentation/listeners/performance.rb
* Same comment about synchronizing on a mutable samples hash.
* If the duration is always greater than 32768, then min will
incorrectly be 32768
spec/unit/util/instrumentation/listeners/performance_spec.rb
* Same comment about require 'spec/spec_helper'
-----------------------------------------------------
COMMIT 6/8
lib/puppet/util/instrumentation/listeners/process_name.rb
* @oldname is set, but never used
* Same comment about synchronizing on a mutable @mutex
* The scroller thread should be stopped if the listener is disabled
spec/unit/util/instrumentation/listeners/process_name_spec.rb
* require 'spec/spec_helper'
-----------------------------------------------------
COMMIT 7/8
lib/puppet/indirector/instrumentation_probe.rb
lib/puppet/indirector/instrumentation_probe/local.rb
lib/puppet/indirector/instrumentation_probe/rest.rb
* Getting a list of "probes" doesn't exactly work, due to rest
interface pluralizing (something to just document when telling people
how to use this feature):
curl -k -H 'Accept: pson' -X GET -H "Content-Type: text/pson" -d
"{}" "https://localhost:8140/production/instrumentation_probes/all";
Forbidden request: localhost(127.0.0.1) access to /
instrumentation_prob/all [search] at line 105
Have to say .../instrumentation_probe_search/all instead.
lib/puppet/util/instrumentation/indirection_probe.rb
* :docuemnt_type misspelled
spec/unit/indirector/instrumentation_probe/local_spec.rb
spec/unit/indirector/instrumentation_probe/rest_spec.rb
spec/unit/util/instrumentation/indirection_probe_spec.rb
-----------------------------------------------------
COMMIT 8/8
lib/puppet/indirector/indirection.rb
* no comments
Josh
On May 17, 10:32 am, Brice Figureau <[email protected]>
wrote:
> This listener stores the last 20 event durations for a given label.
> It is not terribly useful except giving an idea of the api.
>
> Signed-off-by: Brice Figureau <[email protected]>
> ---
> lib/puppet/util/instrumentation/listeners/log.rb | 24 +++++++++++++
> .../util/instrumentation/listeners/log_spec.rb | 35
> ++++++++++++++++++++
> 2 files changed, 59 insertions(+), 0 deletions(-)
> create mode 100644 lib/puppet/util/instrumentation/listeners/log.rb
> create mode 100755 spec/unit/util/instrumentation/listeners/log_spec.rb
>
> diff --git a/lib/puppet/util/instrumentation/listeners/log.rb
> b/lib/puppet/util/instrumentation/listeners/log.rb
> new file mode 100644
> index 0000000..34d6564
> --- /dev/null
> +++ b/lib/puppet/util/instrumentation/listeners/log.rb
> @@ -0,0 +1,24 @@
> +require 'monitor'
> +
> +# This is an exampleinstrumentationlistener that stores the last
> +# 20 instrumentated probe run time.
> +Puppet::Util::Instrumentation.new_listener(:log) do
> +
> + SIZE = 20
> +
> + attr_accessor :last_logs
> +
> + def notify(label, event, data)
> + return if event == :start
> + @last_logs ||= {}.extend(MonitorMixin)
> + log_line = "#{label} took #{data[:finished] - data[:started]}"
> + @last_logs.synchronize {
> + (@last_logs[label] ||= []) << log_line
> + @last_logs[label].shift if @last_logs[label].length > SIZE
> + }
> + end
> +
> + def data
> + @last_logs
> + end
> +end
> \ No newline at end of file
> diff --git a/spec/unit/util/instrumentation/listeners/log_spec.rb
> b/spec/unit/util/instrumentation/listeners/log_spec.rb
> new file mode 100755
> index 0000000..6b97e0c
> --- /dev/null
> +++ b/spec/unit/util/instrumentation/listeners/log_spec.rb
> @@ -0,0 +1,35 @@
> +Dir.chdir(File.dirname(__FILE__)) { (s = lambda { |f| File.exist?(f) ?
> require(f) : Dir.chdir("..") { s.call(f) } }).call("spec/spec_helper.rb") }
> +
> +require 'puppet/util/instrumentation'
> +
> +Puppet::Util::Instrumentation.init
> +log = Puppet::Util::Instrumentation.listener(:log)
> +
> +describe log do
> + before(:each) do
> + @log = log.new
> + end
> +
> + it "should have a notify method" do
> + @log.should respond_to(:notify)
> + end
> +
> + it "should have a data method" do
> + @log.should respond_to(:data)
> + end
> +
> + it "should keep data for stop event" do
> + @log.notify(:test, :stop, { :started => Time.at(123456789), :finished =>
> Time.at(123456790)})
> + @log.data.should == {:test=>["test took 1.0"]}
> + end
> +
> + it "should not keep data for start event" do
> + @log.notify(:test, :start, { :started => Time.at(123456789)})
> + @log.data.should be_nil
> + end
> +
> + it "should not keep more than 20 events per label" do
> + 25.times { @log.notify(:test, :stop, { :started => Time.at(123456789),
> :finished => Time.at(123456790)}) }
> + @log.data[:test].size.should == 20
> + end
> +end
> \ No newline at end of file
> --
> 1.7.5.1
--
You received this message because you are subscribed to the Google Groups
"Puppet Developers" group.
To post to this group, send email to [email protected].
To unsubscribe from this group, send email to
[email protected].
For more options, visit this group at
http://groups.google.com/group/puppet-dev?hl=en.
