Log path for graphql requests

Include the path for graphql requests since some applications may expose multiple graphql endpoints.

CHANGELOG.md

@@ -1,4 +1,13 @@
  # CHANGELOG
+## v0.8 - 2021-11-22
+
+### Added
+`operationName` for GQL requests
+
+### Changed
+`path` now always path and not sometimes `operationName`
+
+
 ## v0.7 - 2021-08-16
 
 ### Added
@@ -44,4 +53,4 @@ is not a 200-level status
 
 ### Changed
 
-* better handle queries with no operationName
+* better handle queries with no operationName

README.md

@@ -23,7 +23,7 @@ In addition, about 2/3 of those requests are GraphQL requests. Their first log
 line simply says `POST /graphql` every time, which gives us no insight into what
 the request is actually doing. `Uinta.Plug` will extract GraphQL query names
 when they exist to make these log lines more useful without having to enable
-debug logs: `QUERY messagesForLocation` or `MUTATION createMessage`.
+debug logs: `QUERY messagesForLocation (/graphql)` or `MUTATION createMessage (/graphql)`.
 
 For smaller organizations, the ability to filter out lines pertaining to certain
 requests paths can also be useful to cut down on log noise. Kubernetes health

lib/uinta/formatter.ex

@@ -47,7 +47,7 @@ defmodule Uinta.Formatter do
     - `message` is the message to be formatted. This should be iodata
   (typically String or iolist)
     - `timestamp` is a timestamp formatted according to
-  `Logger.Formatter.time/0`
+  `t:Logger.Formatter.time/0`
     - `metadata` is a keyword list containing metadata that will be included
   with the log line
 

lib/uinta/plug.ex

@@ -150,7 +150,8 @@ if Code.ensure_loaded?(Plug) do
       %{
         connection_type: connection_type(conn),
         method: method(conn, graphql_info),
-        path: path(conn, graphql_info),
+        path: conn.request_path,
+        operation_name: graphql_info[:operation],
         query: query(graphql_info, opts),
         status: Integer.to_string(conn.status),
         timing: formatted_diff(diff),
@@ -174,7 +175,8 @@ if Code.ensure_loaded?(Plug) do
     end
 
     defp format_line(info, :string) do
-      log = [info.method, ?\s, info.path]
+      log = [info.method, ?\s, info.operation_name || info.path]
+      log = if is_nil(info.operation_name), do: log, else: [log, " (", info.path, ")"]
       log = if is_nil(info.variables), do: log, else: [log, " with ", info.variables]
       log = [log, " - ", info.connection_type, ?\s, info.status, " in ", info.timing]
       if is_nil(info.query), do: log, else: [log, "\nQuery: ", info.query]
@@ -184,10 +186,6 @@ if Code.ensure_loaded?(Plug) do
     defp method(_, %{type: type}), do: type
     defp method(conn, _), do: conn.method
 
-    @spec path(Plug.Conn.t(), graphql_info()) :: String.t()
-    defp path(_, %{operation: operation}), do: operation
-    defp path(conn, _), do: conn.request_path
-
     @spec query(graphql_info(), opts()) :: String.t() | nil
     defp query(_, %{include_unnamed_queries: false}), do: nil
     defp query(%{query: query}, _), do: query

mix.exs

@@ -8,7 +8,7 @@ defmodule Uinta.MixProject do
       app: :uinta,
       name: "Uinta",
       description: "Simpler structured logs and lower log volume for Elixir apps",
-      version: "0.7.0",
+      version: "0.8.0",
       elixir: "~> 1.8",
       source_url: @project_url,
       homepage_url: @project_url,

test/uinta/plug_test.exs

@@ -137,7 +137,7 @@ defmodule Uinta.PlugTest do
         MyPlug.call(conn(:post, "/graphql", params), [])
       end)
 
-    assert message =~ ~r"\[info\]  QUERY getUser - Sent 200 in [0-9]+[µm]s"u
+    assert message =~ ~r"\[info\]  QUERY getUser \(/graphql\) - Sent 200 in [0-9]+[µm]s"u
   end
 
   test "logs proper json to console" do
@@ -160,7 +160,7 @@ defmodule Uinta.PlugTest do
       end)
 
     assert message =~
-             ~r"{\"duration_ms\":[0-9]+\.?[0-9]+,\"method\":\"QUERY\",\"path\":\"getUser\",\"status\":\"200\",\"timing\":\"[0-9]+[µm]s\"}"u
+             ~r"{\"duration_ms\":[0-9]+\.?[0-9]+,\"method\":\"QUERY\",\"operation_name\":\"getUser\",\"path\":\"/graphql\",\"status\":\"200\",\"timing\":\"[0-9]+[µm]s\"}"u
   end
 
   test "logs paths with double slashes and trailing slash" do