From 01daba12a1ec3e2ad29f64722df90f01e3baac45 Mon Sep 17 00:00:00 2001 From: Nicolas Dular Date: Thu, 11 May 2023 17:46:00 +0200 Subject: [PATCH 1/5] Add new llm logger for debugging AI features Adds a new logger and debugging statements for AI features. --- doc/administration/logs/index.md | 12 ++++++++++++ doc/development/ai_features.md | 10 +++++++++- ee/app/services/llm/base_service.rb | 17 +++++++++++++++-- ee/app/workers/llm/completion_worker.rb | 14 ++++++++++++++ ee/lib/gitlab/llm/anthropic/client.rb | 11 +++++++++-- ee/lib/gitlab/llm/completions/base.rb | 3 ++- .../graphql_subscription_response_service.rb | 8 +++++++- ee/lib/gitlab/llm/logger.rb | 11 +++++++++++ ee/lib/gitlab/llm/open_ai/client.rb | 7 ++++++- ee/lib/gitlab/llm/vertex_ai/client.rb | 14 ++++++++++++-- 10 files changed, 97 insertions(+), 10 deletions(-) create mode 100644 ee/lib/gitlab/llm/logger.rb diff --git a/doc/administration/logs/index.md b/doc/administration/logs/index.md index 82675c4ce39825..0b346384c41289 100644 --- a/doc/administration/logs/index.md +++ b/doc/administration/logs/index.md @@ -1032,6 +1032,18 @@ can be used. } ``` +## `llm.log` **(ULTIMATE SAAS)** + +> [Introduced](https://gitlab.com/gitlab-org/gitlab/-/merge_requests/120506) in GitLab 16.0. + +This file logs information related to the +[Ai features](../../user/ai_features.md). + +Depending on your installation method, this file is located at: + +- Omnibus GitLab: `/var/log/gitlab/gitlab-rails/llm.log` +- Installations from source: `/home/git/gitlab/log/llm.log` + ## Registry logs For Omnibus GitLab installations, Container Registry logs are in `/var/log/gitlab/registry/current`. diff --git a/doc/development/ai_features.md b/doc/development/ai_features.md index d53b20274126e4..e1a4c2957b8c4b 100644 --- a/doc/development/ai_features.md +++ b/doc/development/ai_features.md @@ -89,7 +89,15 @@ To populate the embedding database for GitLab chat: 1. Open a rails console 1. Run [this script](https://gitlab.com/gitlab-com/gl-infra/production/-/issues/10588#note_1373586079) to populate the embedding database -### Configure GCP Vertex access +### Debugging + +To gather more insights about the full request, there is the `Gitlab::Llm::Logger` which can be used for debugging logs. To follow the debugging messages related to the AI requests on the abstraction layer, you can use: + +```shell +tail -f log/llm.log +``` + +### Internal-Only GCP account access In order to obtain a GCP service key for local development, please follow the steps below: diff --git a/ee/app/services/llm/base_service.rb b/ee/app/services/llm/base_service.rb index 4930417dae9107..18fe8870c6049e 100644 --- a/ee/app/services/llm/base_service.rb +++ b/ee/app/services/llm/base_service.rb @@ -8,10 +8,14 @@ def initialize(user, resource, options = {}) @user = user @resource = resource @options = options + @logger = Gitlab::Llm::Logger.build end def execute - return error(INVALID_MESSAGE) unless valid? + unless valid? + logger.debug(message: "Returning from Service due to validation") + return error(INVALID_MESSAGE) + end perform end @@ -24,7 +28,7 @@ def valid? private - attr_reader :user, :resource, :options + attr_reader :user, :resource, :options, :logger def perform raise NotImplementedError @@ -33,6 +37,15 @@ def perform def perform_async(user, resource, action_name, options) request_id = SecureRandom.uuid options[:request_id] = request_id + + logger.debug( + message: "Enqueuing CompletionWorker", + user_id: user.id, + resource_id: resource.id, + resource_class: resource.class.name, + action_name: action_name + ) + ::Llm::CompletionWorker.perform_async(user.id, resource.id, resource.class.name, action_name, options) success(request_id: request_id) diff --git a/ee/app/workers/llm/completion_worker.rb b/ee/app/workers/llm/completion_worker.rb index 3571a87134537e..ad9e1163e41273 100644 --- a/ee/app/workers/llm/completion_worker.rb +++ b/ee/app/workers/llm/completion_worker.rb @@ -10,6 +10,13 @@ class CompletionWorker urgency :low def perform(user_id, resource_id, resource_class, ai_action_name, options = {}) + logger.debug( + message: "Performing CompletionWorker", + user_id: user_id, + resource_id: resource_id, + action_name: ai_action_name + ) + return unless Feature.enabled?(:openai_experimentation) options.symbolize_keys! @@ -23,12 +30,19 @@ def perform(user_id, resource_id, resource_class, ai_action_name, options = {}) return unless resource.send_to_ai? params = { request_id: options.delete(:request_id) } + ai_completion = ::Gitlab::Llm::CompletionsFactory.completion(ai_action_name.to_sym, params) + logger.debug(message: "Getting Completion Service from factory", class_name: ai_completion.class.name) + ai_completion.execute(user, resource, options) if ai_completion end private + def logger + @logger ||= Gitlab::Llm::Logger.build + end + def find_resource(resource_id, resource_class) resource_class.classify.constantize.find_by_id(resource_id) end diff --git a/ee/lib/gitlab/llm/anthropic/client.rb b/ee/lib/gitlab/llm/anthropic/client.rb index edcb81c7b5789b..d3bef2f51633ad 100644 --- a/ee/lib/gitlab/llm/anthropic/client.rb +++ b/ee/lib/gitlab/llm/anthropic/client.rb @@ -13,21 +13,28 @@ class Client def initialize(user) @user = user + @logger = Gitlab::Llm::Logger.build end def complete(prompt:, **options) return unless enabled? - Gitlab::HTTP.post( + logger.debug("Performing request to Anthropic") + + response = Gitlab::HTTP.post( URI.join(URL, '/v1/complete'), headers: request_headers, body: request_body(prompt: prompt, options: options).to_json ) + + logger.debug("Received response from Anthropic") + + response end private - attr_reader :user + attr_reader :user, :logger retry_methods_with_exponential_backoff :complete diff --git a/ee/lib/gitlab/llm/completions/base.rb b/ee/lib/gitlab/llm/completions/base.rb index 745bd11925e3bc..e660e98dfdf5f6 100644 --- a/ee/lib/gitlab/llm/completions/base.rb +++ b/ee/lib/gitlab/llm/completions/base.rb @@ -7,11 +7,12 @@ class Base def initialize(ai_prompt_class, params = {}) @ai_prompt_class = ai_prompt_class @params = params + @logger = Gitlab::Llm::Logger.build end private - attr_reader :ai_prompt_class, :params + attr_reader :ai_prompt_class, :params, :logger end end end diff --git a/ee/lib/gitlab/llm/graphql_subscription_response_service.rb b/ee/lib/gitlab/llm/graphql_subscription_response_service.rb index 829055e641941c..7efe87693aa59d 100644 --- a/ee/lib/gitlab/llm/graphql_subscription_response_service.rb +++ b/ee/lib/gitlab/llm/graphql_subscription_response_service.rb @@ -8,6 +8,7 @@ def initialize(user, resource, response_modifier, options:) @resource = resource @response_modifier = response_modifier @options = options + @logger = Gitlab::Llm::Logger.build end def execute @@ -22,12 +23,17 @@ def execute errors: response_modifier.errors } + logger.debug( + message: "Broadcasting AI response", + data: data + ) + GraphqlTriggers.ai_completion_response(user.to_global_id, resource.to_global_id, data) end private - attr_reader :user, :resource, :response_modifier, :options + attr_reader :user, :resource, :response_modifier, :options, :logger def generate_response_body(response_body) return response_body if options[:markup_format].nil? || options[:markup_format] == :raw diff --git a/ee/lib/gitlab/llm/logger.rb b/ee/lib/gitlab/llm/logger.rb new file mode 100644 index 00000000000000..32c1114b4b28f4 --- /dev/null +++ b/ee/lib/gitlab/llm/logger.rb @@ -0,0 +1,11 @@ +# frozen_string_literal: true + +module Gitlab + module Llm + class Logger < ::Gitlab::JsonLogger + def self.file_name_noext + 'llm' + end + end + end +end diff --git a/ee/lib/gitlab/llm/open_ai/client.rb b/ee/lib/gitlab/llm/open_ai/client.rb index 938b332430e0dc..0fadcfb162523a 100644 --- a/ee/lib/gitlab/llm/open_ai/client.rb +++ b/ee/lib/gitlab/llm/open_ai/client.rb @@ -14,6 +14,7 @@ class Client def initialize(user, request_timeout: nil) @user = user @request_timeout = request_timeout + @logger = Gitlab::Llm::Logger.build end def chat(content:, moderated: nil, **options) @@ -71,7 +72,7 @@ def moderations(input:, **options) retry_methods_with_exponential_backoff :chat, :completions, :edits, :embeddings, :moderations - attr_reader :user, :request_timeout + attr_reader :user, :request_timeout, :logger def client @client ||= OpenAI::Client.new(access_token: access_token, request_timeout: request_timeout) @@ -108,10 +109,14 @@ def warn_if_moderated_unset(moderated, default:) def request(endpoint:, moderated:, **options) return unless enabled? + logger.debug(message: "Performing request to OpenAi", endpoint: endpoint) + moderate!(:input, moderation_input(endpoint, options)) if should_moderate?(:input, moderated) response = client.public_send(endpoint, **options) # rubocop:disable GitlabSecurity/PublicSend + logger.debug(message: "Received response from OpenAi") + track_cost(endpoint, response.parsed_response&.dig('usage')) if should_moderate?(:output, moderated) diff --git a/ee/lib/gitlab/llm/vertex_ai/client.rb b/ee/lib/gitlab/llm/vertex_ai/client.rb index f82c11ad23f860..c7cecf0a886f35 100644 --- a/ee/lib/gitlab/llm/vertex_ai/client.rb +++ b/ee/lib/gitlab/llm/vertex_ai/client.rb @@ -6,7 +6,9 @@ module VertexAi class Client include ::Gitlab::Llm::Concerns::ExponentialBackoff - def initialize(_user); end + def initialize(_user) + @logger = Gitlab::Llm::Logger.build + end # @param [String] content - Input string # @param [Hash] options - Additional options to pass to the request @@ -63,14 +65,22 @@ def code(content:, **options) private + attr_reader :logger + retry_methods_with_exponential_backoff :chat, :text, :code, :messages_chat def request(content:, config:, **options) - HTTParty.post( # rubocop: disable Gitlab/HTTParty + logger.debug(message: "Performing request to Vertex", config: config) + + response = HTTParty.post( # rubocop: disable Gitlab/HTTParty config.url, headers: config.headers, body: config.payload(content).merge(options).to_json ) + + logger.debug(message: "Received response from Vertex") + + response end def service_name -- GitLab From 98d93f3e81fb7fa04806a497f869e7673f750d6d Mon Sep 17 00:00:00 2001 From: Nicolas Dular Date: Fri, 12 May 2023 17:57:15 +0200 Subject: [PATCH 2/5] Log the request_id --- ee/app/services/llm/base_service.rb | 1 + 1 file changed, 1 insertion(+) diff --git a/ee/app/services/llm/base_service.rb b/ee/app/services/llm/base_service.rb index 18fe8870c6049e..dac7daef38d1dd 100644 --- a/ee/app/services/llm/base_service.rb +++ b/ee/app/services/llm/base_service.rb @@ -43,6 +43,7 @@ def perform_async(user, resource, action_name, options) user_id: user.id, resource_id: resource.id, resource_class: resource.class.name, + request_id: request_id, action_name: action_name ) -- GitLab From 7b7ddeafe423801176f51e948eac9195ec361906 Mon Sep 17 00:00:00 2001 From: Nicolas Dular Date: Mon, 15 May 2023 14:23:10 +0200 Subject: [PATCH 3/5] Remove logger initialization --- ee/lib/gitlab/llm/completions/base.rb | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/ee/lib/gitlab/llm/completions/base.rb b/ee/lib/gitlab/llm/completions/base.rb index e660e98dfdf5f6..745bd11925e3bc 100644 --- a/ee/lib/gitlab/llm/completions/base.rb +++ b/ee/lib/gitlab/llm/completions/base.rb @@ -7,12 +7,11 @@ class Base def initialize(ai_prompt_class, params = {}) @ai_prompt_class = ai_prompt_class @params = params - @logger = Gitlab::Llm::Logger.build end private - attr_reader :ai_prompt_class, :params, :logger + attr_reader :ai_prompt_class, :params end end end -- GitLab From 4052c546c18b3ec9484221681d6f6a220a94413e Mon Sep 17 00:00:00 2001 From: Nicolas Dular Date: Mon, 15 May 2023 14:24:50 +0200 Subject: [PATCH 4/5] Fix docs --- doc/development/ai_features.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/doc/development/ai_features.md b/doc/development/ai_features.md index e1a4c2957b8c4b..32055ec83c2de8 100644 --- a/doc/development/ai_features.md +++ b/doc/development/ai_features.md @@ -97,7 +97,7 @@ To gather more insights about the full request, there is the `Gitlab::Llm::Logge tail -f log/llm.log ``` -### Internal-Only GCP account access +### Configure GCP Vertex access In order to obtain a GCP service key for local development, please follow the steps below: -- GitLab From d6bb44866b07fdc6560ced784c9e71e0e91ff296 Mon Sep 17 00:00:00 2001 From: Suzanne Selhorn Date: Mon, 15 May 2023 16:25:59 +0000 Subject: [PATCH 5/5] Fix OpenAI naming and docs --- doc/administration/logs/index.md | 4 ++-- doc/development/ai_features.md | 3 ++- ee/lib/gitlab/llm/open_ai/client.rb | 4 ++-- 3 files changed, 6 insertions(+), 5 deletions(-) diff --git a/doc/administration/logs/index.md b/doc/administration/logs/index.md index 0b346384c41289..3b448292954c08 100644 --- a/doc/administration/logs/index.md +++ b/doc/administration/logs/index.md @@ -1036,8 +1036,8 @@ can be used. > [Introduced](https://gitlab.com/gitlab-org/gitlab/-/merge_requests/120506) in GitLab 16.0. -This file logs information related to the -[Ai features](../../user/ai_features.md). +The `llm.log` file logs information related to +[AI features](../../user/ai_features.md). Depending on your installation method, this file is located at: diff --git a/doc/development/ai_features.md b/doc/development/ai_features.md index 32055ec83c2de8..609226498cb3eb 100644 --- a/doc/development/ai_features.md +++ b/doc/development/ai_features.md @@ -91,7 +91,8 @@ To populate the embedding database for GitLab chat: ### Debugging -To gather more insights about the full request, there is the `Gitlab::Llm::Logger` which can be used for debugging logs. To follow the debugging messages related to the AI requests on the abstraction layer, you can use: +To gather more insights about the full request, use the `Gitlab::Llm::Logger` file to debug logs. +To follow the debugging messages related to the AI requests on the abstraction layer, you can use: ```shell tail -f log/llm.log diff --git a/ee/lib/gitlab/llm/open_ai/client.rb b/ee/lib/gitlab/llm/open_ai/client.rb index 0fadcfb162523a..92d73fbdeffcc6 100644 --- a/ee/lib/gitlab/llm/open_ai/client.rb +++ b/ee/lib/gitlab/llm/open_ai/client.rb @@ -109,13 +109,13 @@ def warn_if_moderated_unset(moderated, default:) def request(endpoint:, moderated:, **options) return unless enabled? - logger.debug(message: "Performing request to OpenAi", endpoint: endpoint) + logger.debug(message: "Performing request to OpenAI", endpoint: endpoint) moderate!(:input, moderation_input(endpoint, options)) if should_moderate?(:input, moderated) response = client.public_send(endpoint, **options) # rubocop:disable GitlabSecurity/PublicSend - logger.debug(message: "Received response from OpenAi") + logger.debug(message: "Received response from OpenAI") track_cost(endpoint, response.parsed_response&.dig('usage')) -- GitLab