diff --git a/lib/vedeu/events/event.rb b/lib/vedeu/events/event.rb index 63f7a2488..fb050d899 100644 --- a/lib/vedeu/events/event.rb +++ b/lib/vedeu/events/event.rb @@ -213,7 +213,7 @@ def execute(*args) # # @return [Boolean] def throttling? - @now = Time.now.to_f + @now = Vedeu.clock_time options[:delay] > 0 end @@ -238,7 +238,7 @@ def throttle_expired? # # @return [Boolean] def debouncing? - @now = Time.now.to_f + @now = Vedeu.clock_time @deadline = @now + debounce unless deadline? diff --git a/lib/vedeu/logging/all.rb b/lib/vedeu/logging/all.rb index ea08a2996..feff01eac 100644 --- a/lib/vedeu/logging/all.rb +++ b/lib/vedeu/logging/all.rb @@ -9,6 +9,7 @@ module Logging end # Vedeu +require 'vedeu/logging/clock_time' require 'vedeu/logging/lockless_log_device' require 'vedeu/logging/mono_logger' require 'vedeu/logging/log' diff --git a/lib/vedeu/logging/clock_time.rb b/lib/vedeu/logging/clock_time.rb new file mode 100644 index 000000000..df1607d75 --- /dev/null +++ b/lib/vedeu/logging/clock_time.rb @@ -0,0 +1,34 @@ +module Vedeu + + module Logging + + # If the system supports Process::CLOCK_MONOTONIC use that for + # timestamps. + # + # Vedeu.clock_time # => 15217.232113 (Process::CLOCK_MONOTONIC) + # # => 1447196800.3098037 (Time.now) + # + module ClockTime + + if defined?(Process::CLOCK_MONOTONIC) + def self.clock_time + Process.clock_gettime(Process::CLOCK_MONOTONIC) + end + + else + def self.clock_time + Time.now + end + + end + + end # ClockTime + + end # Logging + + # @!method clock_time + # @see Vedeu::Logging::ClockTime + def_delegators Vedeu::Logging::ClockTime, + :clock_time + +end # Vedeu diff --git a/lib/vedeu/logging/log.rb b/lib/vedeu/logging/log.rb index 627f1d81f..afc98f00c 100644 --- a/lib/vedeu/logging/log.rb +++ b/lib/vedeu/logging/log.rb @@ -54,6 +54,24 @@ def log_stderr(type: :info, message:) $stderr.puts log_entry(type, message) end + # Returns a formatted timestamp. + # eg. [137.7824] + # + # @return [String] + def timestamp + @now = Vedeu.clock_time + @time ||= 0.0 + @last ||= @now + + unless @last == @time + @time += (@now - @last).round(4) + @last = @now + end + + "[#{format('%7.4f', @time.to_s)}] ".rjust(7) + end + alias_method :log_timestamp, :timestamp + private # @return [TrueClass] @@ -163,23 +181,6 @@ def message_types } end - # Returns a formatted timestamp. - # eg. [137.7824] - # - # @return [String] - def timestamp - @now = Time.now.to_f - @time ||= 0.0 - @last ||= @now - - unless @last == @time - @time += (@now - @last).round(4) - @last = @now - end - - "[#{format('%7.4f', @time.to_s)}] ".rjust(7) - end - end # Eigenclass end # Log @@ -195,7 +196,8 @@ def timestamp def_delegators Vedeu::Logging::Log, :log, :log_stdout, - :log_stderr + :log_stderr, + :log_timestamp # :nocov: diff --git a/lib/vedeu/logging/timer.rb b/lib/vedeu/logging/timer.rb index 642d886b8..85df2520c 100644 --- a/lib/vedeu/logging/timer.rb +++ b/lib/vedeu/logging/timer.rb @@ -35,7 +35,7 @@ def timer(message = '', &block) # @return [Vedeu::Logging::Timer] def initialize(message = '') @message = message - @started = Time.now.to_f + @started = Vedeu.clock_time end # Write an entry to the log file stating how long a section of @@ -75,7 +75,7 @@ def measure # # @return [Float] def elapsed - ((Time.now.to_f - started) * 1000).round(3) + ((Vedeu.clock_time - started) * 1000).round(3) end end # Timer diff --git a/lib/vedeu/output/renderers/file.rb b/lib/vedeu/output/renderers/file.rb index 43824c930..ef997d3b3 100644 --- a/lib/vedeu/output/renderers/file.rb +++ b/lib/vedeu/output/renderers/file.rb @@ -67,7 +67,7 @@ def filename # @return [Float] def timestamp if options[:timestamp] - "_#{Time.now.to_f}".freeze + "_#{Vedeu.clock_time}".freeze else ''.freeze diff --git a/test/lib/vedeu/logging/clock_time_test.rb b/test/lib/vedeu/logging/clock_time_test.rb new file mode 100644 index 000000000..bfa9d96c0 --- /dev/null +++ b/test/lib/vedeu/logging/clock_time_test.rb @@ -0,0 +1,13 @@ +require 'test_helper' + +module Vedeu + + module Logging + + describe ClockTime do + + end # ClockTime + + end # Logging + +end # Vedeu diff --git a/test/lib/vedeu/logging/timer_test.rb b/test/lib/vedeu/logging/timer_test.rb index c8a7eefd4..baa3322dc 100644 --- a/test/lib/vedeu/logging/timer_test.rb +++ b/test/lib/vedeu/logging/timer_test.rb @@ -9,18 +9,16 @@ module Logging let(:described) { Vedeu::Logging::Timer } let(:instance) { described.new(_message) } let(:_message) { 'Testing' } - let(:_time) { mock('Time') } - let(:started) { 1434492219.5238185 } + let(:_time) { 1219.523818 } before do - Time.stubs(:now).returns(_time) - _time.stubs(:to_f).returns(started) + Vedeu.stubs(:clock_time).returns(_time) end describe '#initialize' do it { instance.must_be_instance_of(described) } it { instance.instance_variable_get('@message').must_equal(_message) } - it { instance.instance_variable_get('@started').must_equal(started) } + it { instance.instance_variable_get('@started').must_equal(_time) } end describe '.timer' do