diff --git a/ruby/lib/ci/queue.rb b/ruby/lib/ci/queue.rb index 1680b5f9..8cddaf58 100644 --- a/ruby/lib/ci/queue.rb +++ b/ruby/lib/ci/queue.rb @@ -13,6 +13,8 @@ require 'ci/queue/file' require 'ci/queue/grind' require 'ci/queue/bisect' +require 'logger' +require 'fileutils' module CI module Queue @@ -28,6 +30,21 @@ def requeueable?(test_result) requeueable.nil? || requeueable.call(test_result) end + def logger + @logger ||= begin + FileUtils.mkdir_p("log") + Logger.new('log/ci-queue.log') + end + end + + def with_instrumentation(msg) + start = Process.clock_gettime(Process::CLOCK_MONOTONIC, :float_millisecond) + result = yield + duration = Process.clock_gettime(Process::CLOCK_MONOTONIC, :float_millisecond) - start + CI::Queue.logger.info("#{msg} #{duration}ms") + result + end + def shuffle(tests, random) if shuffler shuffler.call(tests, random) diff --git a/ruby/lib/ci/queue/redis/base.rb b/ruby/lib/ci/queue/redis/base.rb index f8bba79e..c10c1ba1 100644 --- a/ruby/lib/ci/queue/redis/base.rb +++ b/ruby/lib/ci/queue/redis/base.rb @@ -11,9 +11,23 @@ class Base ::SocketError, # https://github.com/redis/redis-rb/pull/631 ].freeze + module RedisInstrumentation + def connect(redis_config) + CI::Queue.with_instrumentation("redis connect: ") { super } + end + + def call(command, redis_config) + CI::Queue.with_instrumentation("redis call #{command}: ") { super } + end + + def call_pipelined(commands, redis_config) + CI::Queue.with_instrumentation("redis pipeline #{commands}: ") { super } + end + end + def initialize(redis_url, config) @redis_url = redis_url - @redis = ::Redis.new(url: redis_url) + @redis = ::Redis.new(url: redis_url, middlewares: [RedisInstrumentation]) @config = config end diff --git a/ruby/lib/ci/queue/redis/worker.rb b/ruby/lib/ci/queue/redis/worker.rb index 2eb02a46..ce9ae67a 100644 --- a/ruby/lib/ci/queue/redis/worker.rb +++ b/ruby/lib/ci/queue/redis/worker.rb @@ -199,21 +199,23 @@ def try_to_reserve_lost_test end def push(tests) - @total = tests.size - - if @master = redis.setnx(key('master-status'), 'setup') - redis.multi do |transaction| - transaction.lpush(key('queue'), tests) unless tests.empty? - transaction.set(key('total'), @total) - transaction.set(key('master-status'), 'ready') - - transaction.expire(key('queue'), config.redis_ttl) - transaction.expire(key('total'), config.redis_ttl) - transaction.expire(key('master-status'), config.redis_ttl) + CI::Queue.with_instrumentation("push tests: ") do + @total = tests.size + + if @master = redis.setnx(key('master-status'), 'setup') + redis.multi do |transaction| + transaction.lpush(key('queue'), tests) unless tests.empty? + transaction.set(key('total'), @total) + transaction.set(key('master-status'), 'ready') + + transaction.expire(key('queue'), config.redis_ttl) + transaction.expire(key('total'), config.redis_ttl) + transaction.expire(key('master-status'), config.redis_ttl) + end end + register + redis.expire(key('workers'), config.redis_ttl) end - register - redis.expire(key('workers'), config.redis_ttl) rescue *CONNECTION_ERRORS raise if @master end