DEBUG: Adds debugging log woody handler (#21)

apps/api_key_mgmt/lib/api_key_mgmt/auth.ex

@@ -8,9 +8,13 @@ defmodule ApiKeyMgmt.Auth do
   alias Plugger.Generated.Auth.{SecurityScheme, SecurityScheme.Bearer}
   alias TokenKeeper.{Authenticator, Identity}
 
+  require Logger
+
   @spec authenticate(Context.t(), SecurityScheme.t(), opts :: Keyword.t()) ::
           {:allowed, Context.t()} | {:forbidden, reason :: any}
   def authenticate(context, %Bearer{token: token}, opts) do
+    Logger.debug("Authenticating with context #{inspect(context)}")
+
     with {:ok, identity} <- get_bearer_identity(token, context.request_origin, opts),
          {:ok, context_fragments} <- get_identity_fragments(identity, opts) do
       context = %{
@@ -46,6 +50,11 @@ defmodule ApiKeyMgmt.Auth do
           | {:error, Authenticator.error()}
   defp get_bearer_identity(token, request_origin, opts) do
     client = Authenticator.client(opts[:rpc_context])
+
+    Logger.debug(
+      "Calling token-keeper with client: #{inspect(client)} and opts: #{inspect(opts)}"
+    )
+
     Authenticator.authenticate(client, token, request_origin)
   end
 
@@ -55,7 +64,9 @@ defmodule ApiKeyMgmt.Auth do
     end
   end
 
-  defp get_identity_type_fragments(%TokenKeeper.Identity.User{id: user_id}, opts) do
+  defp get_identity_type_fragments(%TokenKeeper.Identity.User{id: user_id} = user, opts) do
+    Logger.debug("Calling org-management with user: #{inspect(user)} and opts: #{inspect(opts)}")
+
     fragment =
       case get_user_org_fragment(user_id, opts) do
         {:ok, context_fragment} -> %{"org-management" => context_fragment}

apps/api_key_mgmt/lib/api_key_mgmt/handler.ex

@@ -17,6 +17,8 @@ defmodule ApiKeyMgmt.Handler do
 
   alias TokenKeeper.Authority
 
+  require Logger
+
   @default_deployment_id "Production"
 
   defmodule Context do
@@ -60,6 +62,10 @@ defmodule ApiKeyMgmt.Handler do
   @spec __authenticate__(SecurityScheme.t(), Context.t()) ::
           {:allow, Context.t()} | :deny
   def __authenticate__(security_scheme, ctx) do
+    Logger.debug(
+      "Authenticating for handler #{inspect(__MODULE__)} with context: #{inspect(ctx)}"
+    )
+
     case Auth.authenticate(ctx.auth, security_scheme, rpc_context: ctx.rpc) do
       {:allowed, auth_context} ->
         {:allow, %{ctx | auth: auth_context}}

apps/api_key_mgmt/lib/api_key_mgmt/woody/event_handler.ex

@@ -0,0 +1,34 @@
+defmodule ApiKeyMgmt.Woody.EventHandler do
+  @moduledoc false
+
+  alias :woody_event_handler, as: WoodyEventHandler
+
+  require Logger
+
+  # @behaviour WoodyEventHandler
+
+  @typep event :: WoodyEventHandler.event()
+  @typep meta :: WoodyEventHandler.meta()
+
+  # @exposed_meta [
+  #   :event,
+  #   :service,
+  #   :function,
+  #   :type,
+  #   :metadata,
+  #   :url,
+  #   :deadline,
+  #   :execution_duration_ms
+  # ]
+
+  @spec handle_event(event(), Woody.Context.rpc_id(), meta(), any()) ::
+          any
+  def handle_event(event, rpc_id, meta, _opts) do
+    Logger.info(inspect({event, rpc_id, meta}))
+    # level = WoodyEventHandler.get_event_severity(event, meta)
+    # message = Woody.EventHandler.Formatter.format(rpc_id, event, meta)
+    # metadata = WoodyEventHandler.format_meta(event, meta, @exposed_meta)
+
+    # Logger.log(level, message, metadata)
+  end
+end

apps/org_management/lib/org_management/client/woody.ex

@@ -9,13 +9,18 @@ defmodule OrgManagement.Client.Woody do
   alias Woody.Context
   alias Woody.Generated.OrgManagement.AuthContextProvider.AuthContextProvider.Client
 
+  require Logger
+
   @spec get_user_context(user_id :: String.t(), Context.t()) ::
           {:ok, ContextFragment.t()} | {:exception, UserNotFound.t()}
   def get_user_context(user_id, woody_ctx) do
     config = Application.fetch_env!(:org_management, __MODULE__)
+    client = Client.new(woody_ctx, config[:url], config[:opts] || [])
 
-    woody_ctx
-    |> Client.new(config[:url], config[:opts] || [])
-    |> Client.get_user_context(user_id)
+    Logger.debug(
+      "Actually trying to call org-management via protocol with client: #{inspect(client)} and config: #{inspect(config)}"
+    )
+
+    Client.get_user_context(client, user_id)
   end
 end

compose.yaml

@@ -12,6 +12,8 @@ services:
       - .:$PWD
     environment:
       - MIX_ENV=test
+    ports:
+      - 8080:8080
     depends_on:
       db:
         condition: service_healthy

config/config.exs

@@ -1,6 +1,6 @@
 import Config
 
-config :logger, level: :warn
+config :logger, level: :debug
 
 config :logger, :console,
   metadata: [
@@ -21,7 +21,8 @@ config :logger, :console,
 config :api_key_mgmt,
   ecto_repos: [ApiKeyMgmt.Repository]
 
-config :api_key_mgmt, ApiKeyMgmt.Repository, migration_primary_key: [name: :id, type: :string]
-config :api_key_mgmt, ApiKeyMgmt.Repository, migration_foreign_key: [name: :id, type: :string]
+config :api_key_mgmt, ApiKeyMgmt.Repository,
+  migration_primary_key: [name: :id, type: :string],
+  migration_foreign_key: [name: :id, type: :string]
 
 import_config "#{Mix.env()}.exs"

config/dev.exs

@@ -1,3 +1,3 @@
 import Config
 
-config :logger, level: :warn
+config :logger, level: :debug

config/runtime.exs

@@ -5,7 +5,7 @@ default_woody_client_options = [
   # DISCUSS consider configuring scoper handler
   #   https://github.com/valitydev/scoper/blob/87110f5bd72c0e39ba9b7d6eca88fea91b8cd357/src/scoper_woody_event_handler.erl
   # See hellgate' `sys.config`
-  event_handler: Woody.EventHandler.Default
+  event_handler: ApiKeyMgmt.Woody.EventHandler
 ]
 
 # Configure release environment here

config/test.exs

@@ -1,6 +1,6 @@
 import Config
 
-config :logger, level: :warn
+config :logger, level: :debug
 
 # config :logger, :console,
 #   format: {LogstashLoggerFormatter, :format}