diff --git a/config/initializers/click_house.rb b/config/initializers/click_house.rb index 7230eab1b03b28552c897a6d55a41c71357b0346..ecf1ccb97bf874e19a7394b1a9a3a74ca3b9d41c 100644 --- a/config/initializers/click_house.rb +++ b/config/initializers/click_house.rb @@ -17,6 +17,18 @@ ) end + if Rails.env.development? || Rails.env.test? + config.logger = ::ClickHouse::Logger.build + config.log_proc = ->(query) do + structured_log(query.to_sql) + end + else + config.logger = Logger.new('/dev/null') + config.log_proc = ->(query) do + structured_log(query.to_redacted_sql) + end + end + config.json_parser = Gitlab::Json config.http_post_proc = ->(url, headers, body) do options = { @@ -32,3 +44,7 @@ ClickHouse::Client::Response.new(response.body, response.code, response.headers) end end + +def structured_log(query_string) + { query: query_string, correlation_id: Labkit::Correlation::CorrelationId.current_id.to_s } +end diff --git a/gems/click_house-client/lib/click_house/client.rb b/gems/click_house-client/lib/click_house/client.rb index 2a9c5e402f5d370dd97fbb76dfaf9b8384ab1e54..1ca3653c45f915af7660ecfb398c40d535a3395f 100644 --- a/gems/click_house-client/lib/click_house/client.rb +++ b/gems/click_house-client/lib/click_house/client.rb @@ -100,6 +100,10 @@ def self.insert_csv(query, io, database, configuration = self.configuration) db = lookup_database(configuration, database) query = ClickHouse::Client::Query.build(query) + + log_contents = configuration.log_proc.call(query) + configuration.logger.info(log_contents) + ActiveSupport::Notifications.instrument('sql.click_house', { query: query, database: database }) do |instrument| # Use a multipart POST request where the placeholders are sent with the param_ prefix # See: https://github.com/ClickHouse/ClickHouse/issues/8842 diff --git a/gems/click_house-client/lib/click_house/client/configuration.rb b/gems/click_house-client/lib/click_house/client/configuration.rb index 882b37993dc83a804ca9f9ad1fdc5815fbd2dc3e..4a71934466f2b053d61570bebc84bf79a2f709b7 100644 --- a/gems/click_house-client/lib/click_house/client/configuration.rb +++ b/gems/click_house-client/lib/click_house/client/configuration.rb @@ -18,6 +18,9 @@ class Configuration # # *json_parser*: object for parsing JSON strings, it should respond to the "parse" method # + # *logger*: object for receiving logger commands. Default `$stdout` + # *log_proc*: any output (e.g. structure) to wrap around the query for every statement + # # Example: # # Gitlab::ClickHouse::Client.configure do |c| @@ -31,6 +34,11 @@ class Configuration # } # ) # + # c.logger = MyLogger.new + # c.log_proc = ->(query) do + # { query_body: query.to_redacted_sql } + # end + # # c.http_post_proc = lambda do |url, headers, body| # options = { # headers: headers, @@ -44,13 +52,15 @@ class Configuration # # c.json_parser = JSON # end - attr_accessor :http_post_proc, :json_parser + attr_accessor :http_post_proc, :json_parser, :logger, :log_proc attr_reader :databases def initialize @databases = {} @http_post_proc = nil @json_parser = JSON + @logger = ::Logger.new($stdout) + @log_proc = ->(query) { query.to_sql } end def register_database(name, **args) diff --git a/gems/click_house-client/spec/click_house/client_spec.rb b/gems/click_house-client/spec/click_house/client_spec.rb index 51cc097a228fbc8a78611ceceb85f53dcf2dddf2..ab2407a83d7fbd2af45b9d2e642941dbf5c6ad37 100644 --- a/gems/click_house-client/spec/click_house/client_spec.rb +++ b/gems/click_house-client/spec/click_house/client_spec.rb @@ -30,6 +30,9 @@ let(:configuration) do ClickHouse::Client::Configuration.new.tap do |config| + config.log_proc = ->(query) do + { query_string: query.to_sql } + end config.register_database(:test_db, **database_config) config.http_post_proc = ->(_url, _headers, _query) { body = File.read(query_result_fixture) @@ -94,5 +97,34 @@ end.to raise_error(ClickHouse::Client::DatabaseError, 'some error') end end + + describe 'default logging' do + let(:fake_logger) { instance_double("Logger", info: 'logged!') } + let(:query_string) { 'SELECT * FROM issues' } + + before do + configuration.logger = fake_logger + end + + shared_examples 'proper logging' do + it 'calls the custom logger and log_proc' do + expect(fake_logger).to receive(:info).at_least(:once).with({ query_string: query_string }) + + described_class.select(query_object, :test_db, configuration) + end + end + + context 'when query is a string' do # rubocop:disable RSpec/MultipleMemoizedHelpers + let(:query_object) { query_string } + + it_behaves_like 'proper logging' + end + + context 'when query is a Query object' do # rubocop:disable RSpec/MultipleMemoizedHelpers + let(:query_object) { ClickHouse::Client::Query.new(raw_query: query_string) } + + it_behaves_like 'proper logging' + end + end end end diff --git a/lib/click_house/logger.rb b/lib/click_house/logger.rb new file mode 100644 index 0000000000000000000000000000000000000000..90af644799b3f046e2905bf18f4f69c851b05cf7 --- /dev/null +++ b/lib/click_house/logger.rb @@ -0,0 +1,11 @@ +# frozen_string_literal: true + +module ClickHouse + class Logger < ::Gitlab::JsonLogger + exclude_context! + + def self.file_name_noext + 'clickhouse' + end + end +end diff --git a/spec/lib/gitlab/database/click_house_client_spec.rb b/spec/lib/gitlab/database/click_house_client_spec.rb index 8e4a474cc9b010dbd4e8f242835c85d1c4cba099..6e63ae565578084e4e0ccb83e44aa66f0083ed31 100644 --- a/spec/lib/gitlab/database/click_house_client_spec.rb +++ b/spec/lib/gitlab/database/click_house_client_spec.rb @@ -115,4 +115,23 @@ def format_row(event) end end end + + describe 'logging' do + let(:query_string) { "SELECT * FROM events WHERE id IN (4, 5, 6)" } + + context 'on dev and test environments' do + it 'logs the un-redacted query' do + expect(ClickHouse::Client.configuration.logger).to receive(:info).with({ + query: query_string, + correlation_id: a_kind_of(String) + }) + + ClickHouse::Client.select(query_string, :main) + end + + it 'has a ClickHouse logger' do + expect(ClickHouse::Client.configuration.logger).to be_a(ClickHouse::Logger) + end + end + end end