diff --git a/lib/logflare/alerting.ex b/lib/logflare/alerting.ex index ceea7b013d..0368b1a6bf 100644 --- a/lib/logflare/alerting.ex +++ b/lib/logflare/alerting.ex @@ -18,11 +18,11 @@ defmodule Logflare.Alerting do alias Logflare.Cluster alias Logflare.Endpoints alias Logflare.Google.BigQuery.GCPConfig - alias Logflare.Google.BigQuery.GenUtils alias Logflare.Repo alias Logflare.Teams alias Logflare.TeamUsers.TeamUser alias Logflare.User + alias Logflare.Utils.LoggerMetadata require Logger require OpenTelemetry.Tracer @@ -431,72 +431,51 @@ defmodule Logflare.Alerting do @spec execute_alert_query(AlertQuery.t(), use_query_cache: boolean) :: {:ok, QueryResult.t()} | {:error, any()} def execute_alert_query(%AlertQuery{user: %User{}} = alert_query, opts \\ []) do - Logger.debug("Executing AlertQuery | #{alert_query.name} | #{alert_query.id}") - - endpoints = Endpoints.list_endpoints_by(user_id: alert_query.user_id) - use_query_cache = Keyword.get(opts, :use_query_cache, true) - - alerts = - list_alert_queries_by_user_id(alert_query.user_id) - |> Enum.filter(&(&1.id != alert_query.id)) - - with {:ok, expanded_query} <- - Logflare.Sql.expand_subqueries( - alert_query.language, - alert_query.query, - endpoints ++ alerts - ), - {:ok, transformed_query} <- - Logflare.Sql.transform(alert_query.language, expanded_query, alert_query.user_id), - {:ok, result} <- - BigQueryAdaptor.execute_query( - { - alert_query.user.bigquery_project_id || GCPConfig.default_project_id(), - alert_query.user.bigquery_dataset_id, - alert_query.user.id - }, - {transformed_query, []}, - parameterMode: "NAMED", - maxResults: 1000, - location: alert_query.user.bigquery_dataset_location, - use_query_cache: use_query_cache, - labels: %{ - "alert_id" => alert_query.id - }, - query_type: :alerts - ) do - {:ok, result} - else - {:error, %Tesla.Env{body: body}} -> - decoded = Jason.decode!(body)["error"] - - error = - decoded - |> GenUtils.process_bq_errors(alert_query.user_id) - |> case do - %{"message" => msg} -> msg - other -> other - end - - Logger.error("Alert query execution failed with bad response", - user_id: alert_query.user_id, - alert_query_id: alert_query.id, - alert_name: alert_query.name, - possible_reservation_error: BigQueryAdaptor.reservation_error?(decoded), - error_string: inspect(error) - ) - - {:error, error} - - {:error, error} -> - Logger.error("Alert query execution failed with an unknown error", - user_id: alert_query.user_id, - alert_query_id: alert_query.id, - alert_name: alert_query.name, - error_string: inspect(error) - ) - - {:error, error} - end + LoggerMetadata.with_metadata(alert_query_logger_metadata(alert_query), fn -> + Logger.debug("Executing AlertQuery | #{alert_query.name} | #{alert_query.id}") + + endpoints = Endpoints.list_endpoints_by(user_id: alert_query.user_id) + use_query_cache = Keyword.get(opts, :use_query_cache, true) + + alerts = + list_alert_queries_by_user_id(alert_query.user_id) + |> Enum.filter(&(&1.id != alert_query.id)) + + with {:ok, expanded_query} <- + Logflare.Sql.expand_subqueries( + alert_query.language, + alert_query.query, + endpoints ++ alerts + ), + {:ok, transformed_query} <- + Logflare.Sql.transform(alert_query.language, expanded_query, alert_query.user_id), + {:ok, result} <- + BigQueryAdaptor.execute_query( + { + alert_query.user.bigquery_project_id || GCPConfig.default_project_id(), + alert_query.user.bigquery_dataset_id, + alert_query.user.id + }, + {transformed_query, []}, + parameterMode: "NAMED", + maxResults: 1000, + location: alert_query.user.bigquery_dataset_location, + use_query_cache: use_query_cache, + labels: %{ + "alert_id" => alert_query.id + }, + query_type: :alerts + ) do + {:ok, result} + end + end) + end + + defp alert_query_logger_metadata(%AlertQuery{} = alert_query) do + [ + user_id: alert_query.user_id, + alert_query_id: alert_query.id, + alert_name: alert_query.name + ] end end diff --git a/lib/logflare/backends/adaptor/bigquery_adaptor.ex b/lib/logflare/backends/adaptor/bigquery_adaptor.ex index cdbd63abf9..7999d496cd 100644 --- a/lib/logflare/backends/adaptor/bigquery_adaptor.ex +++ b/lib/logflare/backends/adaptor/bigquery_adaptor.ex @@ -21,6 +21,7 @@ defmodule Logflare.Backends.Adaptor.BigQueryAdaptor do alias Logflare.Backends.Ecto.SqlUtils alias Logflare.Backends.IngestEventQueue alias Logflare.Backends.Adaptor.QueryResult + alias Logflare.Backends.QueryError alias Logflare.BigQuery.SchemaTypes alias Logflare.Billing alias Logflare.BqRepo @@ -685,7 +686,7 @@ defmodule Logflare.Backends.Adaptor.BigQueryAdaptor do query_opts :: Keyword.t() ) :: {:ok, QueryResult.t()} - | {:error, any()} + | {:error, QueryError.t()} defp execute_user_query(%User{} = user, project_id, query_string, bq_params, query_opts) when is_non_empty_binary(query_string) and is_list(bq_params) and is_list(query_opts) do case BqRepo.query_with_sql_and_params( @@ -704,20 +705,77 @@ defmodule Logflare.Backends.Adaptor.BigQueryAdaptor do bq_params: bq_params })} - {:error, %{body: body}} -> - decoded = Jason.decode!(body)["error"] - error = GenUtils.process_bq_errors(decoded, user.id) - maybe_warn_reservation_error(decoded, user, project_id, query_opts) - {:error, error} + {:error, error} -> + query_error = + error + |> to_query_error(user.id) + |> QueryError.log( + user_id: user.id, + bigquery_project_id: project_id + ) + + maybe_warn_reservation_error(query_error, user, project_id, query_opts) + + {:error, query_error} + end + end - {:error, err} when is_atom(err) -> - {:error, GenUtils.process_bq_errors(err, user.id)} + @spec to_query_error(Tesla.Env.t() | GenUtils.transport_error(), pos_integer()) :: + QueryError.t() + defp to_query_error(error, _user_id) when error in [:timeout, :closed, :emfile] do + %QueryError{ + kind: :connection_error, + raw_error: error, + backend: __MODULE__ + } + end - {:error, err} -> - {:error, err} + defp to_query_error(%{body: body}, user_id) when is_binary(body) do + with {:ok, %{"error" => raw_error}} <- Jason.decode(body), + %{"message" => _message} = processed_error <- + GenUtils.process_bq_errors(raw_error, user_id) do + processed_error + |> query_error_kind() + |> query_error(processed_error) + else + _error -> query_error(:backend_error, body) end end + defp to_query_error(%{body: body}, _user_id) do + query_error(:backend_error, body) + end + + @spec query_error_kind(map()) :: QueryError.kind() + defp query_error_kind(%{"reason" => "billingTierLimitExceeded"}), do: :backend_error + defp query_error_kind(%{"reason" => "invalidQuery"}), do: :invalid_query + + defp query_error_kind(%{"errors" => errors}) when is_list(errors) do + if Enum.any?(errors, &match?(%{"reason" => "invalidQuery"}, &1)) do + :invalid_query + else + :backend_error + end + end + + defp query_error_kind(processed_error) do + with %{"message" => message} when is_binary(message) <- processed_error, + true <- String.starts_with?(message, ["Unrecognized name:", "Field name"]) do + :invalid_query + else + _ -> :backend_error + end + end + + @spec query_error(QueryError.kind(), term()) :: QueryError.t() + defp query_error(kind, raw_error) do + %QueryError{ + kind: kind, + raw_error: raw_error, + backend: __MODULE__ + } + end + @spec pg_sql_to_bq_sql(sql :: String.t()) :: String.t() defp pg_sql_to_bq_sql(sql) when is_non_empty_binary(sql) do sql @@ -741,19 +799,25 @@ defmodule Logflare.Backends.Adaptor.BigQueryAdaptor do end @spec maybe_warn_reservation_error( - decoded :: any(), + error :: QueryError.t(), user :: User.t(), project_id :: String.t(), query_opts :: Keyword.t() ) :: :ok - defp maybe_warn_reservation_error(decoded, %User{} = user, project_id, query_opts) do - if reservation_error?(decoded) and not caller_logs_own_errors?(query_opts) do + defp maybe_warn_reservation_error( + %QueryError{raw_error: error}, + %User{} = user, + project_id, + query_opts + ) do + with true <- reservation_error?(error), + false <- caller_logs_own_errors?(query_opts) do Logger.warning("Possible BigQuery reservation error", user_id: user.id, project_id: project_id, reservation: Keyword.get(query_opts, :reservation), query_type: Keyword.get(query_opts, :query_type), - bq_error_message: decoded["message"] + bq_error_message: error["message"] ) end diff --git a/lib/logflare/backends/adaptor/clickhouse_adaptor.ex b/lib/logflare/backends/adaptor/clickhouse_adaptor.ex index 62ef4a830d..bd856f6a85 100644 --- a/lib/logflare/backends/adaptor/clickhouse_adaptor.ex +++ b/lib/logflare/backends/adaptor/clickhouse_adaptor.ex @@ -30,6 +30,7 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptor do alias Logflare.Backends.Ecto.SqlUtils alias Logflare.Backends.IngestEventQueue alias Logflare.Backends.Adaptor.QueryResult + alias Logflare.Backends.QueryError alias Logflare.LogEvent alias Logflare.LogEvent.TypeDetection @@ -344,7 +345,7 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptor do statement :: iodata(), params :: map | [term] | [row :: [term]] | iodata | Enumerable.t(), [Ch.query_option()] - ) :: {:ok, Ch.Result.t()} | {:error, Exception.t()} + ) :: {:ok, Ch.Result.t()} | {:error, QueryError.t()} def execute_ch_query(backend, statement, params \\ [], opts \\ []) def execute_ch_query(%Backend{} = backend, statement, params, opts) @@ -367,26 +368,16 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptor do {:ok, %Ch.Result{} = result} -> {:ok, decode_ch_result(result)} - {:error, %Ch.Error{message: error_msg}} when is_non_empty_binary(error_msg) -> - Logger.warning( - "ClickHouse query failed: #{inspect(error_msg)}", - backend_id: backend.id, - host: read_host(backend) - ) - - {:error, "Error executing ClickHouse query"} - - {:error, %{message: message}} when is_non_empty_binary(message) -> - Logger.warning( - "ClickHouse query failed: #{inspect(message)}", - backend_id: backend.id, - host: read_host(backend) - ) - - {:error, "Error executing ClickHouse query"} - - {:error, _} -> - {:error, "Error executing ClickHouse query"} + {:error, error} -> + {:error, + error + |> to_query_error() + |> QueryError.log( + user_id: backend.user_id, + backend_id: backend.id, + backend_token: backend.token, + host: read_host(backend) + )} end end end @@ -414,6 +405,43 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptor do @ch_slow_pool_checkout_ms end + @spec to_query_error(term()) :: QueryError.t() + defp to_query_error(%Ch.Error{} = error) do + error + |> ch_query_error_kind() + |> query_error(error) + end + + defp to_query_error(%DBConnection.ConnectionError{} = error) do + query_error(:connection_error, error) + end + + defp to_query_error(error) do + query_error(:backend_error, error) + end + + @spec ch_query_error_kind(term()) :: QueryError.kind() + defp ch_query_error_kind(%Ch.Error{code: code}) when code in [47, 62], do: :invalid_query + + defp ch_query_error_kind(%Ch.Error{message: message}) when is_binary(message) do + if message =~ "UNKNOWN_IDENTIFIER" or message =~ "SYNTAX_ERROR" do + :invalid_query + else + :backend_error + end + end + + defp ch_query_error_kind(%Ch.Error{}), do: :backend_error + + @spec query_error(QueryError.kind(), term()) :: QueryError.t() + defp query_error(kind, raw_error) do + %QueryError{ + kind: kind, + raw_error: raw_error, + backend: __MODULE__ + } + end + @spec execute_direct_query(url :: String.t(), config :: map(), statement :: String.t()) :: {:ok, list()} | {:error, term()} defp execute_direct_query(url, config, statement) do @@ -439,15 +467,15 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptor do {:ok, %Ch.Result{} = result} -> {:ok, decode_ch_result(result)} - {:error, _} -> - {:error, "Error executing ClickHouse query"} + {:error, error} -> + {:error, to_query_error(error)} end after GenServer.stop(pid) end - {:error, _} -> - {:error, "Error executing ClickHouse query"} + {:error, error} -> + {:error, to_query_error(error)} end end @@ -528,7 +556,7 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptor do Creates one table per log type: `_logs`, `_metrics`, and `_traces`. """ - @spec provision_ingest_tables(Backend.t()) :: :ok | {:error, Exception.t()} + @spec provision_ingest_tables(Backend.t()) :: :ok | {:error, QueryError.t()} def provision_ingest_tables(%Backend{config: config} = backend) do cloud? = clickhouse_cloud?(backend) diff --git a/lib/logflare/backends/adaptor/postgres_adaptor.ex b/lib/logflare/backends/adaptor/postgres_adaptor.ex index 2dcbadb5fb..3f8212cdf3 100644 --- a/lib/logflare/backends/adaptor/postgres_adaptor.ex +++ b/lib/logflare/backends/adaptor/postgres_adaptor.ex @@ -23,6 +23,7 @@ defmodule Logflare.Backends.Adaptor.PostgresAdaptor do alias Logflare.Backends.Backend alias Logflare.Backends.Ecto.SqlUtils alias Logflare.Backends.Adaptor.QueryResult + alias Logflare.Backends.QueryError alias Logflare.SingleTenant alias Logflare.Sources.Source alias Logflare.Sql @@ -91,12 +92,17 @@ defmodule Logflare.Backends.Adaptor.PostgresAdaptor do def execute_query(%Backend{} = backend, %Ecto.Query{} = query, _opts) do mod = PgRepo.create_repo(backend) - result = - query - |> mod.all() - |> Enum.map(&nested_map_update/1) + try do + result = + query + |> mod.all() + |> Enum.map(&nested_map_update/1) - {:ok, QueryResult.new(result, pg_meta(result))} + {:ok, QueryResult.new(result, pg_meta(result))} + rescue + error in [Postgrex.Error, DBConnection.ConnectionError, Ecto.QueryError] -> + {:error, error |> to_query_error() |> log_query_error(backend)} + end end def execute_query(%Backend{} = backend, query_string, opts) @@ -119,6 +125,9 @@ defmodule Logflare.Backends.Adaptor.PostgresAdaptor do end {:ok, QueryResult.new(rows, pg_meta(rows))} + else + {:error, error} -> + {:error, error |> to_query_error() |> log_query_error(backend)} end end @@ -212,6 +221,68 @@ defmodule Logflare.Backends.Adaptor.PostgresAdaptor do Map.put(config, :url, updated) end + @spec to_query_error( + :cannot_connect + | Postgrex.Error.t() + | DBConnection.ConnectionError.t() + | %Ecto.QueryError{} + ) :: QueryError.t() + defp to_query_error(:cannot_connect) do + query_error(:connection_error, :cannot_connect) + end + + defp to_query_error(%Postgrex.Error{} = error) do + error + |> postgres_query_error_kind() + |> query_error(error) + end + + defp to_query_error(%DBConnection.ConnectionError{} = error) do + query_error(:connection_error, error) + end + + defp to_query_error(%Ecto.QueryError{} = error) do + query_error(:backend_error, error) + end + + @spec postgres_query_error_kind(Postgrex.Error.t()) :: QueryError.kind() + defp postgres_query_error_kind(%Postgrex.Error{postgres: %{code: code}}) + when code in [:undefined_column, :syntax_error], + do: :invalid_query + + defp postgres_query_error_kind(%Postgrex.Error{postgres: %{pg_code: pg_code}}) + when pg_code in ["42703", "42601"], + do: :invalid_query + + defp postgres_query_error_kind(%Postgrex.Error{} = error) do + message = Exception.message(error) + + if message =~ "undefined_column" or message =~ "syntax_error" or + message =~ ~r/column\s+["'`]?([^"'`\s]+)["'`]?\s+does not exist/ do + :invalid_query + else + :backend_error + end + end + + @spec query_error(QueryError.kind(), term()) :: QueryError.t() + defp query_error(kind, raw_error) do + %QueryError{ + kind: kind, + raw_error: raw_error, + backend: __MODULE__ + } + end + + @spec log_query_error(QueryError.t(), Backend.t()) :: QueryError.t() + defp log_query_error(%QueryError{} = error, %Backend{} = backend) do + QueryError.log(error, + user_id: backend.user_id, + backend_id: backend.id, + backend_token: backend.token + ) + end + # expose PgRepo functions defdelegate create_repo(backend), to: PgRepo defdelegate table_name(source), to: PgRepo diff --git a/lib/logflare/backends/query_error.ex b/lib/logflare/backends/query_error.ex new file mode 100644 index 0000000000..a1ae942789 --- /dev/null +++ b/lib/logflare/backends/query_error.ex @@ -0,0 +1,37 @@ +defmodule Logflare.Backends.QueryError do + @moduledoc false + + require Logger + + @enforce_keys [:kind, :raw_error, :backend] + defstruct [:kind, :raw_error, :backend, :description] + + @type kind :: :invalid_query | :connection_error | :backend_error + @type t :: %__MODULE__{ + kind: kind(), + raw_error: term(), + backend: module(), + description: String.t() | nil + } + + @spec log(t(), Keyword.t()) :: t() + def log(error, metadata \\ []) + + def log(%__MODULE__{kind: :invalid_query} = error, metadata) when is_list(metadata) do + error + end + + def log(%__MODULE__{} = error, metadata) when is_list(metadata) do + Logger.error( + "Backend query error", + metadata + |> Keyword.merge( + backend: inspect(error.backend), + error_kind: error.kind, + error_string: inspect(error.raw_error) + ) + ) + + error + end +end diff --git a/lib/logflare/ecto/bigquery/bq_repo.ex b/lib/logflare/ecto/bigquery/bq_repo.ex index a3e39db363..3499ded7f0 100644 --- a/lib/logflare/ecto/bigquery/bq_repo.ex +++ b/lib/logflare/ecto/bigquery/bq_repo.ex @@ -18,7 +18,7 @@ defmodule Logflare.BqRepo do optional(atom()) => any() } @type query_result :: - {:ok, results()} | {:error, Tesla.Env.t()} + {:ok, results()} | {:error, Tesla.Env.t() | GenUtils.transport_error()} @spec query_with_sql_and_params( Logflare.User.t(), diff --git a/lib/logflare/endpoints.ex b/lib/logflare/endpoints.ex index 78795fc846..83a6194fbe 100644 --- a/lib/logflare/endpoints.ex +++ b/lib/logflare/endpoints.ex @@ -9,8 +9,9 @@ defmodule Logflare.Endpoints do alias Logflare.Alerting alias Logflare.Alerting.AlertQuery alias Logflare.Backends - alias Logflare.Backends.Backend alias Logflare.Backends.Adaptor.QueryResult + alias Logflare.Backends.Backend + alias Logflare.Backends.QueryError alias Logflare.Endpoints.PiiRedactor alias Logflare.Endpoints.EndpointQuery alias Logflare.Endpoints.Resolver @@ -35,7 +36,7 @@ defmodule Logflare.Endpoints do @typep origin :: User.t() | TeamUser.t() | OauthAccessToken.t() @typep run_query_return :: {:ok, %{required(:rows) => [term()], optional(atom()) => any()}} - | {:error, String.t()} + | {:error, String.t() | QueryError.t()} defguardp is_integer_or_string(value) when is_integer(value) or is_non_empty_binary(value) diff --git a/lib/logflare/google/bigquery/gen_utils.ex b/lib/logflare/google/bigquery/gen_utils.ex index 2194e64c28..90b93271c2 100644 --- a/lib/logflare/google/bigquery/gen_utils.ex +++ b/lib/logflare/google/bigquery/gen_utils.ex @@ -21,6 +21,9 @@ defmodule Logflare.Google.BigQuery.GenUtils do @default_dataset_location "US" @table_ttl 604_800_000 + @type transport_error :: :emfile | :timeout | :closed + @type google_api_result :: {:ok, any()} | {:error, Tesla.Env.t() | transport_error()} + @doc """ Returns the default TTL used (in days) for initializing the table. """ @@ -152,15 +155,14 @@ defmodule Logflare.Google.BigQuery.GenUtils do "#{account_id}" end - @spec maybe_parse_google_api_result({:ok, any()} | {:error, Tesla.Env.t()}) :: - {:ok, any()} | {:error, Tesla.Env.t()} + @spec maybe_parse_google_api_result(google_api_result()) :: google_api_result() def maybe_parse_google_api_result({:error, %Tesla.Env{} = teslaenv}) do {:error, teslaenv} end def maybe_parse_google_api_result(x), do: x - @spec get_tesla_error_message(:emfile | :timeout | :closed | Tesla.Env.t()) :: String.t() + @spec get_tesla_error_message(transport_error() | Tesla.Env.t()) :: String.t() def get_tesla_error_message(%Tesla.Env{} = message) do case JSON.decode(message.body) do {:ok, body} -> diff --git a/lib/logflare/logs/search_operations.ex b/lib/logflare/logs/search_operations.ex index df93c5418e..6f4c54387d 100644 --- a/lib/logflare/logs/search_operations.ex +++ b/lib/logflare/logs/search_operations.ex @@ -24,6 +24,7 @@ defmodule Logflare.Logs.SearchOperations do alias Logflare.SourceSchemas alias Logflare.Sources alias Logflare.Utils.Chart, as: ChartUtils + alias Logflare.Utils.LoggerMetadata alias Logflare.Utils.List, as: ListUtils @type chart_period :: :day | :hour | :minute | :second @@ -70,20 +71,31 @@ defmodule Logflare.Logs.SearchOperations do @spec execute_backend_query(SO.t()) :: {:ok, map()} | {:error, term()} defp execute_backend_query(%SO{backend_type: :postgres} = so) do - backend = postgres_backend(so) + source_logger_metadata(so) + |> LoggerMetadata.with_metadata(fn -> + backend = postgres_backend(so) - PostgresAdaptor.execute_query(backend, so.query, query_type: :search) + PostgresAdaptor.execute_query(backend, so.query, query_type: :search) + end) end defp execute_backend_query(%SO{} = so) do bq_project_id = so.source.user.bigquery_project_id || GCPConfig.default_project_id() %{bigquery_dataset_id: dataset_id} = GenUtils.get_bq_user_info(so.source.token) - BigQueryAdaptor.execute_query( - {bq_project_id, dataset_id, so.source.user.id}, - so.query, - query_type: :search - ) + source_logger_metadata(so) + |> LoggerMetadata.with_metadata(fn -> + BigQueryAdaptor.execute_query( + {bq_project_id, dataset_id, so.source.user.id}, + so.query, + query_type: :search + ) + end) + end + + @spec source_logger_metadata(SO.t()) :: Keyword.t() + defp source_logger_metadata(%SO{} = so) do + [source_id: so.source.token, source_token: so.source.token] end @spec put_sql_string(SO.t(), QueryResult.t()) :: SO.t() diff --git a/lib/logflare/sql.ex b/lib/logflare/sql.ex index 5a312b85d7..cd75044f78 100644 --- a/lib/logflare/sql.ex +++ b/lib/logflare/sql.ex @@ -158,6 +158,10 @@ defmodule Logflare.Sql do queries :: [AlertQuery.t() | Endpoints.EndpointQuery.t()] ) :: {:ok, String.t()} | {:error, String.t()} + def expand_subqueries(language, "", queries) + when language in @valid_query_languages and is_list(queries), + do: {:error, "Query cannot be empty"} + def expand_subqueries(_language, input, []), do: {:ok, input} def expand_subqueries(language, input, queries) diff --git a/lib/logflare/utils/logger_metadata.ex b/lib/logflare/utils/logger_metadata.ex new file mode 100644 index 0000000000..6e2572ffce --- /dev/null +++ b/lib/logflare/utils/logger_metadata.ex @@ -0,0 +1,16 @@ +defmodule Logflare.Utils.LoggerMetadata do + @moduledoc false + + @spec with_metadata(Keyword.t(), (-> term())) :: term() + def with_metadata(metadata, fun) when is_list(metadata) and is_function(fun, 0) do + previous_metadata = Logger.metadata() + + Logger.metadata(metadata) + + try do + fun.() + after + Logger.reset_metadata(previous_metadata) + end + end +end diff --git a/lib/logflare_web/controllers/api/backend_controller.ex b/lib/logflare_web/controllers/api/backend_controller.ex index 01395bbab6..31cddb6cd7 100644 --- a/lib/logflare_web/controllers/api/backend_controller.ex +++ b/lib/logflare_web/controllers/api/backend_controller.ex @@ -117,9 +117,9 @@ defmodule LogflareWeb.Api.BackendController do conn |> json(%{connected?: true}) - {:error, reason} -> + {:error, _reason} -> conn - |> json(%{connected?: false, reason: reason}) + |> json(%{connected?: false}) end end end diff --git a/lib/logflare_web/controllers/api/fallback_controller.ex b/lib/logflare_web/controllers/api/fallback_controller.ex index 6b3164f1f5..ad648a2c78 100644 --- a/lib/logflare_web/controllers/api/fallback_controller.ex +++ b/lib/logflare_web/controllers/api/fallback_controller.ex @@ -1,6 +1,9 @@ defmodule LogflareWeb.Api.FallbackController do use Phoenix.Controller + alias Ecto.Changeset + alias Logflare.Backends.QueryError + alias LogflareWeb.QueryErrorHelpers def call(conn, {:error, %Changeset{} = changeset}) do errors = Changeset.traverse_errors(changeset, fn _, _, {message, _} -> message end) @@ -45,6 +48,12 @@ defmodule LogflareWeb.Api.FallbackController do |> json(%{error: "Not Found"}) end + def call(conn, {:error, %QueryError{}}) do + conn + |> put_status(400) + |> json(%{error: QueryErrorHelpers.generic_query_error_message()}) + end + def call(conn, {:error, %{} = err_map}) do conn |> put_status(400) diff --git a/lib/logflare_web/controllers/endpoints_controller.ex b/lib/logflare_web/controllers/endpoints_controller.ex index 61a3da7bfe..3a9598d50d 100644 --- a/lib/logflare_web/controllers/endpoints_controller.ex +++ b/lib/logflare_web/controllers/endpoints_controller.ex @@ -3,12 +3,14 @@ defmodule LogflareWeb.EndpointsController do use OpenApiSpex.ControllerSpecs require Logger - alias Logflare.Endpoints + alias Logflare.Backends.QueryError + alias Logflare.Endpoints alias LogflareWeb.JsonParser alias LogflareWeb.OpenApi.Unauthorized alias LogflareWeb.OpenApi.ServerError alias LogflareWeb.OpenApiSchemas.EndpointQuery + alias LogflareWeb.QueryErrorHelpers @plug_parsers_init Plug.Parsers.init( parsers: [JsonParser], @@ -88,8 +90,11 @@ defmodule LogflareWeb.EndpointsController do Logger.debug("Endpoint cache result, #{inspect(result, pretty: true)}") render(conn, "query.json", result: result.rows) - {:error, errors} -> - render(conn, "query.json", error: errors) + {:error, error = %QueryError{}} -> + render(conn, "query.json", error: QueryErrorHelpers.query_error_message(error)) + + {:error, _errors} -> + render(conn, "query.json", error: QueryErrorHelpers.generic_query_error_message()) end end diff --git a/lib/logflare_web/live/alerts/alerts_live.ex b/lib/logflare_web/live/alerts/alerts_live.ex index 9aa3e9d64e..03b407f195 100644 --- a/lib/logflare_web/live/alerts/alerts_live.ex +++ b/lib/logflare_web/live/alerts/alerts_live.ex @@ -11,9 +11,11 @@ defmodule LogflareWeb.AlertsLive do alias Logflare.Alerting.AlertQuery alias Logflare.Backends alias Logflare.Backends.Adaptor.QueryResult + alias Logflare.Backends.QueryError alias Logflare.Endpoints alias Logflare.Repo alias LogflareWeb.QueryComponents + alias LogflareWeb.QueryErrorHelpers alias LogflareWeb.Utils require Logger @@ -235,7 +237,7 @@ defmodule LogflareWeb.AlertsLive do socket |> put_flash( :error, - "Error when running query: #{inspect(err)}" + "Error when running query: #{format_query_error(err)}" )} end end @@ -266,7 +268,7 @@ defmodule LogflareWeb.AlertsLive do socket |> put_flash( :error, - "Error when running query: #{inspect(err)}" + "Error when running query: #{format_query_error(err)}" )} end end @@ -405,6 +407,14 @@ defmodule LogflareWeb.AlertsLive do |> assign(:modal_node, nil)} end + defp format_query_error(%QueryError{} = error) do + QueryErrorHelpers.query_error_message(error) + end + + defp format_query_error(error) when is_binary(error), do: error + + defp format_query_error(_error), do: QueryErrorHelpers.generic_query_error_message() + def handle_info({:query_string_updated, query_string}, socket) do {:noreply, assign(socket, :query_string, query_string)} end diff --git a/lib/logflare_web/live/backends/components.ex b/lib/logflare_web/live/backends/components.ex index 8684fc6bb9..2b6cc507f8 100644 --- a/lib/logflare_web/live/backends/components.ex +++ b/lib/logflare_web/live/backends/components.ex @@ -9,9 +9,11 @@ defmodule LogflareWeb.Backends.Components do ~H""" <.async_result :let={_ok} assign={@status}> <:loading><.indicator icon="spinner" color="tw-text-white" animation="tw-animate-spin" )} /> - <:failed :let={{atom, reason}}> - <% reason = if atom == :error, do: reason, else: "Internal error" %> - <.indicator icon="times" color="tw-text-red-500" )} /> {reason} + <:failed :let={reason}> + <.indicator icon="times" color="tw-text-red-500" )} /> + + {status_error_message(reason)} + <.indicator icon="check" color="tw-text-green-500" )} /> @@ -26,4 +28,12 @@ defmodule LogflareWeb.Backends.Components do """ end + + defp status_error_message({:error, %Logflare.Backends.QueryError{} = query_error}) do + LogflareWeb.QueryErrorHelpers.query_error_message(query_error) + end + + defp status_error_message(_reason) do + LogflareWeb.QueryErrorHelpers.generic_query_error_message() + end end diff --git a/lib/logflare_web/live/endpoints/endpoints_live.ex b/lib/logflare_web/live/endpoints/endpoints_live.ex index feac16d6f3..68596163ef 100644 --- a/lib/logflare_web/live/endpoints/endpoints_live.ex +++ b/lib/logflare_web/live/endpoints/endpoints_live.ex @@ -14,6 +14,7 @@ defmodule LogflareWeb.EndpointsLive do alias Logflare.Endpoints alias Logflare.Endpoints.PiiRedactor alias LogflareWeb.QueryComponents + alias LogflareWeb.QueryErrorHelpers alias Logflare.Utils embed_templates("actions/*", suffix: "_action") @@ -276,9 +277,11 @@ defmodule LogflareWeb.EndpointsLive do |> assign(:total_bytes_processed, nil)} {:error, err} -> + message = if is_binary(err), do: err, else: QueryErrorHelpers.query_error_message(err) + {:noreply, socket - |> put_flash(:error, "Error occured when running query: #{inspect(err)}")} + |> put_flash(:error, "Error occured running query: #{message}")} end end diff --git a/lib/logflare_web/live/query_live.ex b/lib/logflare_web/live/query_live.ex index 091cf62725..7d01a90185 100644 --- a/lib/logflare_web/live/query_live.ex +++ b/lib/logflare_web/live/query_live.ex @@ -11,6 +11,7 @@ defmodule LogflareWeb.QueryLive do alias Logflare.Teams.TeamContext alias LogflareWeb.AuthLive alias LogflareWeb.QueryComponents + alias LogflareWeb.QueryErrorHelpers alias LogflareWeb.Utils def render(assigns) do @@ -308,8 +309,10 @@ defmodule LogflareWeb.QueryLive do |> assign(:total_bytes_processed, total_bytes_processed) {:error, err} -> + message = if is_binary(err), do: err, else: QueryErrorHelpers.query_error_message(err) + socket - |> put_flash(:error, "Error occurred when running query: #{inspect(err)}") + |> put_flash(:error, "Error occurred running query: #{message}") end end end diff --git a/lib/logflare_web/live/search_live/event_context_component.ex b/lib/logflare_web/live/search_live/event_context_component.ex index 108099015c..f678c0e327 100644 --- a/lib/logflare_web/live/search_live/event_context_component.ex +++ b/lib/logflare_web/live/search_live/event_context_component.ex @@ -9,8 +9,6 @@ defmodule LogflareWeb.SearchLive.EventContextComponent do alias Logflare.Sources.Source.BigQuery.SchemaBuilder import LogflareWeb.SearchLive.LogEventComponents, only: [log_event: 1] - require Logger - @impl true def update(assigns, socket) do %{ @@ -94,12 +92,7 @@ defmodule LogflareWeb.SearchLive.EventContextComponent do |> stream(:log_events, events, reset: true)} end - def handle_async(:logs, {:ok, %{error: error, source: source}}, socket) do - Logger.error("Backend context search error for source: #{source.token}", - error_string: inspect(error), - source_id: source.token - ) - + def handle_async(:logs, {:ok, %{error: _error, source: _source}}, socket) do {:noreply, socket |> assign(:logs, AsyncResult.failed(socket.assigns.logs, "An error occurred.")) diff --git a/lib/logflare_web/live/search_live/logs_search_lv.ex b/lib/logflare_web/live/search_live/logs_search_lv.ex index c51c0c99fd..611222faaa 100644 --- a/lib/logflare_web/live/search_live/logs_search_lv.ex +++ b/lib/logflare_web/live/search_live/logs_search_lv.ex @@ -9,6 +9,7 @@ defmodule LogflareWeb.Source.SearchLV do import LogflareWeb.ModalLiveHelpers import LogflareWeb.SearchLV.Utils + alias Logflare.Backends.QueryError alias Logflare.Billing alias Logflare.Logs.SearchQueryExecutor alias Logflare.Logs.SearchOperations @@ -24,6 +25,7 @@ defmodule LogflareWeb.Source.SearchLV do alias Logflare.User alias Logflare.Users alias LogflareWeb.Helpers.BqSchema, as: BqSchemaHelpers + alias LogflareWeb.QueryErrorHelpers alias LogflareWeb.Router.Helpers, as: Routes alias LogflareWeb.SearchLive.FormComponents alias LogflareWeb.SearchLive.SubheadComponents @@ -675,7 +677,7 @@ defmodule LogflareWeb.Source.SearchLV do {:noreply, socket} end - def handle_info({:search_error, search_op}, %{assigns: %{source: source}} = socket) do + def handle_info({:search_error, search_op}, socket) do socket = case search_op.error do :halted -> @@ -686,25 +688,7 @@ defmodule LogflareWeb.Source.SearchLV do |> assign(chart_loading: false) |> put_halt_flash_message(search_op) - %Tesla.Env{status: 400} = err -> - Logger.error("Backend search error for source: #{source.token}", - error_string: inspect(err), - source_id: source.token - ) - - send(self(), :soft_pause) - - socket - |> assign(loading: false) - |> assign(chart_loading: false) - |> put_flash_query_error(err) - err -> - Logger.error("Backend search error for source: #{source.token}", - error_string: inspect(err), - source_id: source.token - ) - send(self(), :soft_pause) socket @@ -1110,30 +1094,14 @@ defmodule LogflareWeb.Source.SearchLV do end end - defp put_flash_query_error(socket, %Tesla.Env{status: 400} = response) do - case Jason.decode(response.body) do - {:ok, %{"error" => %{"message" => "Query exceeded limit for bytes billed:" <> rest}}} -> - [limit | _] = String.split(rest, ".") - - {size, units} = limit |> String.trim() |> String.to_integer() |> Utils.humanize_bytes() - - socket - |> put_flash( - :error, - "Query halted: total bytes processed for this query is expected to be greater than #{round(size)} #{units}" - ) - - _ -> - put_flash_query_error(socket, nil) - end - end + defp put_flash_query_error(socket, response) do + message = + case response do + %QueryError{} = error -> QueryErrorHelpers.query_error_message(error) + _ -> QueryErrorHelpers.generic_query_error_message() + end - defp put_flash_query_error(socket, _response) do - socket - |> put_flash( - :error, - "Backend error! Retry your query. Please contact support if this continues." - ) + put_flash(socket, :error, "Query halted: " <> message) end defp put_halt_flash_message(socket, search_op) do diff --git a/lib/logflare_web/query_error_helpers.ex b/lib/logflare_web/query_error_helpers.ex new file mode 100644 index 0000000000..cff2274d0b --- /dev/null +++ b/lib/logflare_web/query_error_helpers.ex @@ -0,0 +1,164 @@ +defmodule LogflareWeb.QueryErrorHelpers do + @moduledoc false + + alias Logflare.Backends.QueryError + alias LogflareWeb.Utils + + @generic_query_error_message "Backend error! Retry your query. Please contact support if this continues." + + @doc """ + Returns a user-facing query error message from a backend %QueryError{}. + + iex> error = %Logflare.Backends.QueryError{ + ...> kind: :invalid_query, + ...> raw_error: %{"message" => "Unrecognized name: notthere at [1:8]"}, + ...> backend: Logflare.Backends.Adaptor.BigQueryAdaptor + ...> } + iex> LogflareWeb.QueryErrorHelpers.query_error_message(error) + ~s(Field "notthere" does not exist.) + + iex> error = %Logflare.Backends.QueryError{ + ...> kind: :invalid_query, + ...> raw_error: %Ch.Error{message: "Code: 47. DB::Exception: Unknown expression identifier `notthere` in scope SELECT notthere. (UNKNOWN_IDENTIFIER)"}, + ...> backend: Logflare.Backends.Adaptor.ClickHouseAdaptor + ...> } + iex> LogflareWeb.QueryErrorHelpers.query_error_message(error) + ~s(Field "notthere" does not exist.) + + iex> error = %Logflare.Backends.QueryError{ + ...> kind: :invalid_query, + ...> raw_error: %Postgrex.Error{message: ~s|column "notthere" does not exist|}, + ...> backend: Logflare.Backends.Adaptor.PostgresAdaptor + ...> } + iex> LogflareWeb.QueryErrorHelpers.query_error_message(error) + ~s(Field "notthere" does not exist.) + """ + @spec query_error_message(QueryError.t()) :: String.t() + def query_error_message(%QueryError{} = error) do + classified_query_error_message(error) || generic_query_error_message() + end + + @spec generic_query_error_message() :: String.t() + def generic_query_error_message, do: @generic_query_error_message + + defp classified_query_error_message(%QueryError{ + backend: Logflare.Backends.Adaptor.BigQueryAdaptor, + raw_error: %{"reason" => "billingTierLimitExceeded", "message" => message} + }) do + with [_match, limit] <- + Regex.run(~r/Query exceeded limit for bytes billed:\s*(\d+)\./, message) do + {size, units} = limit |> String.to_integer() |> Utils.humanize_bytes() + + "total bytes processed for this query is expected to be greater than #{round(size)} #{units}" + end + end + + defp classified_query_error_message(%QueryError{ + kind: :invalid_query, + backend: backend, + raw_error: raw_error + }) do + case raw_error_message(raw_error) do + message when is_binary(message) -> invalid_query_message(backend, message) + nil -> nil + end + end + + defp classified_query_error_message(%QueryError{}), do: nil + + defp invalid_query_message(Logflare.Backends.Adaptor.BigQueryAdaptor, message) do + case message do + "Query without FROM clause cannot have a WHERE clause" <> _rest -> + message + + _ -> + missing_field_message(Logflare.Backends.Adaptor.BigQueryAdaptor, message) || + generic_query_error_message() + end + end + + defp invalid_query_message(backend, message) do + missing_field_message(backend, message) + end + + defp missing_field_message(backend, message) do + case extract_missing_field(backend, message) do + nil -> + nil + + field -> + ~s(Field "#{field}" does not exist.) + end + end + + defp extract_missing_field( + Logflare.Backends.Adaptor.BigQueryAdaptor, + "Unrecognized name: " <> rest + ) do + rest + |> first_field_token() + |> normalize_field() + end + + defp extract_missing_field( + Logflare.Backends.Adaptor.BigQueryAdaptor, + "Field name " <> rest + ) do + case String.split(rest, " does not exist", parts: 2) do + [field, _] -> normalize_field(field) + _ -> nil + end + end + + defp extract_missing_field(Logflare.Backends.Adaptor.BigQueryAdaptor, _message) do + nil + end + + defp extract_missing_field(Logflare.Backends.Adaptor.ClickHouseAdaptor, message) do + message + |> extract_field(~r/Unknown (?:expression )?identifier:? [`"']?([^`"'\s,;]+)/) + |> normalize_field() + end + + defp extract_missing_field(Logflare.Backends.Adaptor.PostgresAdaptor, message) do + message + |> extract_field(~r/column\s+["'`]?([^"'`\s]+)["'`]?\s+does not exist/) + |> normalize_path_field() + end + + defp extract_field(message, pattern) do + case Regex.run(pattern, message) do + [_match, field] -> field + nil -> nil + end + end + + defp raw_error_message(%{"message" => message}) when is_binary(message), do: message + + defp raw_error_message(%Postgrex.Error{postgres: %{message: message}}) when is_binary(message), + do: message + + defp raw_error_message(%{message: message}) when is_binary(message), do: message + defp raw_error_message(_raw_error), do: nil + + defp normalize_field(nil), do: nil + + defp normalize_field(field) do + Regex.replace(~r/^[`"'.]+|[`"'.,]+$/, field, "") + end + + defp first_field_token(field) do + field + |> String.split([" ", ",", ";"], parts: 2) + |> List.first() + end + + defp normalize_path_field(nil), do: nil + + defp normalize_path_field(field) do + field + |> normalize_field() + |> String.split(".") + |> List.last() + end +end diff --git a/test/e2e/features/logs_search_test.exs b/test/e2e/features/logs_search_test.exs index 11282773ed..1794cea225 100644 --- a/test/e2e/features/logs_search_test.exs +++ b/test/e2e/features/logs_search_test.exs @@ -56,6 +56,16 @@ defmodule E2e.Features.LogsSearchTest do |> refute_has("#logs-list-container", text: non_matching_message) end + test "shows a missing field error from the search page", %{conn: conn, source: source} do + conn + |> visit(~p"/auth/login/single_tenant") + |> assert_path(~p"/dashboard") + |> visit(~p"/sources/#{source.id}/search?#{%{querystring: "s:nonexistent"}}") + |> wait_for_selector(".message .alert", state: "attached") + |> assert_has(".message .alert p", text: "nonexistent") + |> assert_has(".message .alert p", text: "does not exist") + end + test "cancelling the datepicker resumes tailing", %{ conn: conn, source: source diff --git a/test/logflare/alerting_test.exs b/test/logflare/alerting_test.exs index 87531590f0..cc8389a5eb 100644 --- a/test/logflare/alerting_test.exs +++ b/test/logflare/alerting_test.exs @@ -2,10 +2,13 @@ defmodule Logflare.AlertingTest do use Logflare.DataCase, async: false use Oban.Testing, repo: Logflare.Repo + import ExUnit.CaptureLog + alias Logflare.Alerting alias Logflare.Alerting.AlertQuery alias Logflare.Alerting.AlertWorker alias Logflare.Backends.Adaptor.QueryResult + alias Logflare.Backends.QueryError alias Logflare.Utils.Tasks doctest Logflare.SynEventHandler @@ -270,6 +273,49 @@ defmodule Logflare.AlertingTest do assert reservation == user.bigquery_reservation_alerts end + test "execute_alert_query logs backend errors with alert metadata", %{ + user: user + } do + alert_query = insert(:alert, user: user) |> Logflare.Repo.preload([:user]) + + expect(GoogleApi.BigQuery.V2.Api.Jobs, :bigquery_jobs_query, 1, fn _conn, _proj_id, _opts -> + {:error, :timeout} + end) + + previous_metadata = Logger.metadata() + + log = + capture_log( + [level: :error, metadata: [:user_id, :alert_query_id, :alert_name, :error_kind]], + fn -> + assert {:error, + %QueryError{ + kind: :connection_error, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor, + description: nil + }} = + Alerting.execute_alert_query(alert_query) + end + ) + + assert Logger.metadata() == previous_metadata + assert log =~ "Backend query error" + assert log =~ "user_id=#{alert_query.user_id}" + assert log =~ "alert_query_id=#{alert_query.id}" + assert log =~ "alert_name=" + assert log =~ "error_kind=connection_error" + end + + test "execute_alert_query returns an error for empty queries", %{user: user} do + insert(:endpoint, user: user) + + alert_query = + insert(:alert, user: user, query: "") + |> Logflare.Repo.preload([:user]) + + assert {:error, "Query cannot be empty"} = Alerting.execute_alert_query(alert_query) + end + test "execute_alert_query with query composition" do expect(GoogleApi.BigQuery.V2.Api.Jobs, :bigquery_jobs_query, 1, fn _conn, _proj_id, opts -> assert opts[:body].query =~ "current_datetime" diff --git a/test/logflare/backends/adaptor/bigquery_adaptor_test.exs b/test/logflare/backends/adaptor/bigquery_adaptor_test.exs index 3c89166200..fadd93d76b 100644 --- a/test/logflare/backends/adaptor/bigquery_adaptor_test.exs +++ b/test/logflare/backends/adaptor/bigquery_adaptor_test.exs @@ -9,6 +9,7 @@ defmodule Logflare.Backends.Adaptor.BigQueryAdaptorTest do alias Logflare.Backends.Backend alias Logflare.Backends.Adaptor.BigQueryAdaptor alias Logflare.Backends.Adaptor.QueryResult + alias Logflare.Backends.QueryError # Characters illegal in a BigQuery dataset identifier: SQL delimiters, # identifier-quoting characters, whitespace, and shell metacharacters. @@ -218,6 +219,101 @@ defmodule Logflare.Backends.Adaptor.BigQueryAdaptorTest do }} = result end + + test "execute_query translates errors to QueryError", %{user: user} do + stub(GoogleApi.BigQuery.V2.Api.Jobs, :bigquery_jobs_query, fn _conn, _proj_id, _opts -> + {:error, + TestUtils.gen_bq_error("Unrecognized name: notthere at [1:8]", + reason: "invalidQuery" + )} + end) + + project_id = user.bigquery_project_id || "test-project" + + assert {:error, + %QueryError{ + kind: :invalid_query, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor, + description: nil, + raw_error: %{ + "message" => "Unrecognized name: notthere at [1:8]", + "reason" => "invalidQuery" + } + }} = + BigQueryAdaptor.execute_query( + {project_id, user.bigquery_dataset_id, user.id}, + {"select notthere", []}, + [] + ) + end + + test "execute_query normalizes bytes billed limit errors", %{user: user} do + stub(GoogleApi.BigQuery.V2.Api.Jobs, :bigquery_jobs_query, fn _conn, _proj_id, _opts -> + {:error, + TestUtils.gen_bq_error( + "Query exceeded limit for bytes billed: 2000000000. 20004857600 or higher required.", + reason: "billingTierLimitExceeded" + )} + end) + + assert {:error, + %QueryError{ + kind: :backend_error, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor, + description: nil, + raw_error: %{ + "message" => + "Query exceeded limit for bytes billed: 2000000000. 20004857600 or higher required.", + "reason" => "billingTierLimitExceeded" + } + }} = + BigQueryAdaptor.execute_query( + {user.bigquery_project_id || "test-project", user.bigquery_dataset_id, user.id}, + {"select count(*) from logs", []}, + [] + ) + end + + test "execute_query normalizes transport timeout errors", %{user: user} do + stub(GoogleApi.BigQuery.V2.Api.Jobs, :bigquery_jobs_query, fn _conn, _proj_id, _opts -> + {:error, :timeout} + end) + + assert {:error, + %QueryError{ + kind: :connection_error, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor, + description: nil, + raw_error: :timeout + }} = + BigQueryAdaptor.execute_query( + {user.bigquery_project_id || "test-project", user.bigquery_dataset_id, user.id}, + {"select count(*) from logs", []}, + [] + ) + end + + test "execute_query maps non-invalid BigQuery reasons as backend errors", %{user: user} do + stub(GoogleApi.BigQuery.V2.Api.Jobs, :bigquery_jobs_query, fn _conn, _proj_id, _opts -> + {:error, TestUtils.gen_bq_error("backend unavailable", reason: "backendError")} + end) + + assert {:error, + %QueryError{ + kind: :backend_error, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor, + description: nil, + raw_error: %{ + "message" => "backend unavailable", + "reason" => "backendError" + } + }} = + BigQueryAdaptor.execute_query( + {user.bigquery_project_id || "test-project", user.bigquery_dataset_id, user.id}, + {"select count(*) from logs", []}, + [] + ) + end end describe "build_base_query_opts reservation" do diff --git a/test/logflare/backends/adaptor/clickhouse_adaptor/provisioner_test.exs b/test/logflare/backends/adaptor/clickhouse_adaptor/provisioner_test.exs index 180eb2dee0..a28f253914 100644 --- a/test/logflare/backends/adaptor/clickhouse_adaptor/provisioner_test.exs +++ b/test/logflare/backends/adaptor/clickhouse_adaptor/provisioner_test.exs @@ -3,6 +3,7 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptor.ProvisionerTest do alias Logflare.Backends.Adaptor.ClickHouseAdaptor alias Logflare.Backends.Adaptor.ClickHouseAdaptor.Provisioner + alias Logflare.Backends.QueryError import Logflare.ClickHouseMappedEvents @@ -87,7 +88,12 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptor.ProvisionerTest do TestUtils.retry_assert(fn -> assert_receive {:DOWN, ^ref, :process, ^pid, - {:shutdown, {:error, "Error executing ClickHouse query"}}}, + {:shutdown, + {:error, + %QueryError{ + kind: :connection_error, + backend: Logflare.Backends.Adaptor.ClickHouseAdaptor + }}}}, 5_000 end) end diff --git a/test/logflare/backends/adaptor/clickhouse_adaptor_test.exs b/test/logflare/backends/adaptor/clickhouse_adaptor_test.exs index 248d72d477..96516eb5da 100644 --- a/test/logflare/backends/adaptor/clickhouse_adaptor_test.exs +++ b/test/logflare/backends/adaptor/clickhouse_adaptor_test.exs @@ -16,6 +16,7 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptorTest do alias Logflare.Backends.Backend alias Logflare.Backends.Ecto.SqlUtils alias Logflare.Backends.Adaptor.QueryResult + alias Logflare.Backends.QueryError alias Logflare.Lql.BackendTransformer.ClickHouse, as: ClickHouseLQLTransformer alias Logflare.Lql.Rules.FilterRule @@ -87,7 +88,51 @@ defmodule Logflare.Backends.Adaptor.ClickHouseAdaptorTest do result = ClickHouseAdaptor.execute_ch_query(backend, "INVALID SQL QUERY") - assert {:error, _} = result + assert {:error, %QueryError{} = error} = result + assert error.backend == ClickHouseAdaptor + assert error.kind in [:invalid_query, :connection_error] + + if error.kind == :invalid_query do + assert %Ch.Error{} = error.raw_error + assert error.description == nil + end + end + + test "normalizes missing field query errors", %{backend: backend} do + expect(Ch, :query, fn _pool, _statement, _params, _opts -> + {:error, + %Ch.Error{ + code: 47, + message: + "Code: 47. DB::Exception: Unknown expression identifier `notthere` in scope SELECT notthere. (UNKNOWN_IDENTIFIER)" + }} + end) + + assert {:error, + %QueryError{ + kind: :invalid_query, + backend: Logflare.Backends.Adaptor.ClickHouseAdaptor, + raw_error: %Ch.Error{ + code: 47, + message: + "Code: 47. DB::Exception: Unknown expression identifier `notthere` in scope SELECT notthere. (UNKNOWN_IDENTIFIER)" + }, + description: nil + }} = ClickHouseAdaptor.execute_ch_query(backend, "SELECT notthere") + end + + test "normalizes ClickHouse server errors as backend errors", %{backend: backend} do + expect(Ch, :query, fn _pool, _statement, _params, _opts -> + {:error, %Ch.Error{code: 999, message: "Backend server error"}} + end) + + assert {:error, + %QueryError{ + kind: :backend_error, + backend: Logflare.Backends.Adaptor.ClickHouseAdaptor, + raw_error: %Ch.Error{code: 999, message: "Backend server error"}, + description: nil + }} = ClickHouseAdaptor.execute_ch_query(backend, "SELECT 1") end test "logs a warning when connection checkout is slow", %{backend: backend} do diff --git a/test/logflare/backends/adaptor/postgres_adaptor_test.exs b/test/logflare/backends/adaptor/postgres_adaptor_test.exs index cd1ca3e510..024a11aaae 100644 --- a/test/logflare/backends/adaptor/postgres_adaptor_test.exs +++ b/test/logflare/backends/adaptor/postgres_adaptor_test.exs @@ -9,6 +9,7 @@ defmodule Logflare.Backends.Adaptor.PostgresAdaptorTest do alias Logflare.Backends.Adaptor.PostgresAdaptor.SharedRepo alias Logflare.Backends.AdaptorSupervisor alias Logflare.Backends.Adaptor.QueryResult + alias Logflare.Backends.QueryError alias Logflare.Endpoints alias Logflare.SystemMetrics.AllLogsLogged @@ -95,6 +96,71 @@ defmodule Logflare.Backends.Adaptor.PostgresAdaptorTest do ) end + test "execute_query/3 normalizes Ecto query undefined column errors", %{ + backend: backend, + source: source + } do + log_event = build(:log_event, source: source, test: "data") + + assert {:ok, _} = Backends.ingest_logs([log_event], source) + + query = + from(l in PostgresAdaptor.table_name(source), + select: field(l, :notthere) + ) + + TestUtils.retry_assert(fn -> + assert {:error, + %QueryError{ + kind: :invalid_query, + backend: Logflare.Backends.Adaptor.PostgresAdaptor, + raw_error: %Postgrex.Error{}, + description: nil + } = error} = PostgresAdaptor.execute_query(backend, query, []) + + assert Exception.message(error.raw_error) =~ "notthere" + end) + end + + test "execute_query/3 normalizes raw SQL undefined column errors", %{ + backend: backend, + source: source + } do + log_event = build(:log_event, source: source, test: "data") + + assert {:ok, _} = Backends.ingest_logs([log_event], source) + + query = "select notthere from #{PostgresAdaptor.table_name(source)}" + + TestUtils.retry_assert(fn -> + assert {:error, + %QueryError{ + kind: :invalid_query, + backend: Logflare.Backends.Adaptor.PostgresAdaptor, + raw_error: %Postgrex.Error{}, + description: nil + } = error} = PostgresAdaptor.execute_query(backend, query, []) + + assert Exception.message(error.raw_error) =~ "notthere" + end) + end + + test "execute_query/3 normalizes raw SQL syntax errors", %{backend: backend} do + TestUtils.retry_assert(fn -> + assert {:error, + %QueryError{ + kind: :invalid_query, + backend: Logflare.Backends.Adaptor.PostgresAdaptor, + raw_error: %Postgrex.Error{}, + description: nil + } = error} = PostgresAdaptor.execute_query(backend, "select from", []) + + message = Exception.message(error.raw_error) + assert message =~ "syntax_error" + assert message =~ "syntax error" + end) + end + test "ingest/2 and execute_query/2 dispatched message with metadata transformation into list", %{ backend: backend, @@ -165,7 +231,13 @@ defmodule Logflare.Backends.Adaptor.PostgresAdaptorTest do {:error, :cannot_connect} end) - assert {:error, :cannot_connect} = PostgresAdaptor.test_connection(backend) + assert {:error, + %QueryError{ + kind: :connection_error, + backend: Logflare.Backends.Adaptor.PostgresAdaptor, + raw_error: :cannot_connect, + description: nil + }} = PostgresAdaptor.test_connection(backend) end end diff --git a/test/logflare/backends/query_error_test.exs b/test/logflare/backends/query_error_test.exs new file mode 100644 index 0000000000..71adb1800c --- /dev/null +++ b/test/logflare/backends/query_error_test.exs @@ -0,0 +1,97 @@ +defmodule Logflare.Backends.QueryErrorTest do + use ExUnit.Case, async: true + + import ExUnit.CaptureLog + + alias Logflare.Backends.Adaptor.BigQueryAdaptor + alias Logflare.Backends.QueryError + + describe "struct" do + test "stores backend, kind, and raw error detail" do + error = %QueryError{ + kind: :invalid_query, + raw_error: %{"message" => "raw backend message"}, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor, + description: "user-facing description" + } + + assert error.kind == :invalid_query + assert error.raw_error == %{"message" => "raw backend message"} + assert error.backend == BigQueryAdaptor + end + end + + describe "log/2" do + test "does not log invalid query errors" do + error = query_error(raw_error: %{"message" => "raw user query detail"}) + + log = + capture_log( + [level: :error, metadata: [:user_id, :backend_id, :error_kind, :error_string]], + fn -> + assert ^error = + QueryError.log(error, + user_id: 123, + backend_id: 456, + source_token: nil + ) + end + ) + + assert log == "" + end + + test "logs backend errors with user metadata and raw backend detail" do + error = query_error(kind: :backend_error, raw_error: %{"message" => "raw backend detail"}) + + log = + capture_log( + [level: :error, metadata: [:user_id, :backend_id, :error_kind, :error_string]], + fn -> + assert ^error = + QueryError.log(error, + user_id: 123, + backend_id: 456, + source_token: nil + ) + end + ) + + assert log =~ "Backend query error" + assert log =~ "user_id=123" + assert log =~ "backend_id=456" + assert log =~ "error_kind=backend_error" + assert log =~ "raw backend detail" + refute log =~ "source_token=" + end + + test "logs query errors without requiring user metadata" do + error = query_error(raw_error: :timeout, kind: :connection_error) + + log = + capture_log([level: :error, metadata: [:user_id, :error_kind, :error_string]], fn -> + assert ^error = QueryError.log(error) + end) + + assert log =~ "Backend query error" + assert log =~ "error_kind=connection_error" + assert log =~ "timeout" + refute log =~ "user_id=" + end + end + + defp query_error(attrs) do + attrs = + Keyword.merge( + [ + kind: :invalid_query, + raw_error: %{"message" => "backend failed"}, + backend: BigQueryAdaptor, + description: nil + ], + attrs + ) + + struct!(QueryError, attrs) + end +end diff --git a/test/logflare/backends/user_monitoring_test.exs b/test/logflare/backends/user_monitoring_test.exs index 8848c9cbd2..5a3a05c44f 100644 --- a/test/logflare/backends/user_monitoring_test.exs +++ b/test/logflare/backends/user_monitoring_test.exs @@ -8,6 +8,7 @@ defmodule Logflare.Backends.UserMonitoringTest do alias Logflare.Users alias Logflare.Sources alias Logflare.Backends + alias Logflare.Backends.QueryError alias Logflare.Backends.SourceSup alias Logflare.Backends.UserMonitoring alias Logflare.SystemMetrics.AllLogsLogged @@ -67,6 +68,60 @@ defmodule Logflare.Backends.UserMonitoringTest do end) end + test "query error logs are routed to user's system source when monitoring is on", %{ + user: user, + source: source + } do + {:ok, user} = Users.update_user_allowed(user, %{system_monitoring: true}) + system_source = Sources.get_by(user_id: user.id, system_source_type: :logs) + + error = %QueryError{ + kind: :backend_error, + raw_error: %{"message" => "raw query detail"}, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor + } + + TestUtils.retry_assert(fn -> + assert capture_log(fn -> + QueryError.log(error, + user_id: user.id, + source_token: source.token + ) + end) =~ "Backend query error" + + assert Enum.any?( + Backends.list_recent_logs(system_source), + &query_error_log_event?/1 + ) + end) + end + + test "invalid query errors are not routed to user's system source when monitoring is on", %{ + user: user, + source: source + } do + {:ok, user} = Users.update_user_allowed(user, %{system_monitoring: true}) + system_source = Sources.get_by(user_id: user.id, system_source_type: :logs) + + error = %QueryError{ + kind: :invalid_query, + raw_error: %{"message" => "raw user query detail"}, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor + } + + assert capture_log(fn -> + QueryError.log(error, + user_id: user.id, + source_token: source.token + ) + end) == "" + + refute Enum.any?( + Backends.list_recent_logs(system_source), + &query_error_log_event?/1 + ) + end + test "are not routed to user's system source when not monitoring", %{ user: user, source: source @@ -86,6 +141,17 @@ defmodule Logflare.Backends.UserMonitoringTest do end end + defp query_error_log_event?(%{ + body: %{ + "event_message" => "Backend query error", + "metadata" => %{"error_kind" => "backend_error", "error_string" => error_string} + } + }) do + error_string =~ "raw query detail" + end + + defp query_error_log_event?(_event), do: false + describe "system monitoring labels" do setup :start_otel_exporter diff --git a/test/logflare/endpoints/cache_test.exs b/test/logflare/endpoints/cache_test.exs index b83d96921a..7c0a3e860d 100644 --- a/test/logflare/endpoints/cache_test.exs +++ b/test/logflare/endpoints/cache_test.exs @@ -1,6 +1,7 @@ defmodule Logflare.Endpoints.CacheTest do use Logflare.DataCase + alias Logflare.Backends.QueryError alias Logflare.Endpoints describe "cache behavior" do @@ -57,7 +58,12 @@ defmodule Logflare.Endpoints.CacheTest do {:ok, cache_pid} = start_supervised({Logflare.Endpoints.ResultsCache, {endpoint, %{}, []}}) assert Process.alive?(cache_pid) - assert {:error, %{"message" => :timeout}} = Endpoints.run_cached_query(endpoint) + assert {:error, + %QueryError{ + kind: :connection_error, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor, + raw_error: :timeout + }} = Endpoints.run_cached_query(endpoint) refute Process.alive?(cache_pid) end @@ -97,7 +103,12 @@ defmodule Logflare.Endpoints.CacheTest do {:ok, cache_pid} = start_supervised({Logflare.Endpoints.ResultsCache, {endpoint, %{}, []}}) assert Process.alive?(cache_pid) - assert {:error, %{"message" => "BQ Error"}} = Endpoints.run_cached_query(endpoint) + assert {:error, + %QueryError{ + kind: :backend_error, + backend: Logflare.Backends.Adaptor.BigQueryAdaptor, + raw_error: %{"message" => "BQ Error"} + }} = Endpoints.run_cached_query(endpoint) refute Process.alive?(cache_pid) end diff --git a/test/logflare/sql_test.exs b/test/logflare/sql_test.exs index 594a3042d0..64b264ca98 100644 --- a/test/logflare/sql_test.exs +++ b/test/logflare/sql_test.exs @@ -904,6 +904,13 @@ defmodule Logflare.SqlTest do assert {:error, _} = Sql.expand_subqueries(:bq_sql, "select from", [alert]) end + test "expand_subqueries/3 returns an error for empty input" do + alert = build(:alert, name: "my.alert", query: "select 'id' as id", language: :bq_sql) + + assert {:error, "Query cannot be empty"} = Sql.expand_subqueries(:bq_sql, "", [alert]) + assert {:error, "Query cannot be empty"} = Sql.expand_subqueries(:bq_sql, "", []) + end + describe "transform/3 for :postgres backends" do setup do user = insert(:user) diff --git a/test/logflare/utils/logger_metadata_test.exs b/test/logflare/utils/logger_metadata_test.exs new file mode 100644 index 0000000000..d99d09b9b2 --- /dev/null +++ b/test/logflare/utils/logger_metadata_test.exs @@ -0,0 +1,36 @@ +defmodule Logflare.Utils.LoggerMetadataTest do + use ExUnit.Case, async: true + import ExUnit.CaptureLog + + require Logger + alias Logflare.Utils.LoggerMetadata + + describe "with_metadata/2" do + setup do + Logger.metadata(request_id: "before") + end + + test "sets metadata while the function runs and restores previous metadata" do + log = + capture_log([level: :error, metadata: [:request_id, :user_id]], fn -> + LoggerMetadata.with_metadata([user_id: 123], fn -> + Logger.error("test") + end) + end) + + assert log =~ "request_id=before" + assert log =~ "user_id=123" + assert Logger.metadata() == [request_id: "before"] + end + + test "restores previous metadata when the function raises" do + assert_raise RuntimeError, "boom", fn -> + LoggerMetadata.with_metadata([user_id: 123], fn -> + raise "boom" + end) + end + + assert Logger.metadata() == [request_id: "before"] + end + end +end diff --git a/test/logflare_web/controllers/api/backend_controller_test.exs b/test/logflare_web/controllers/api/backend_controller_test.exs index 7f9fe4ea13..8ab66201c1 100644 --- a/test/logflare_web/controllers/api/backend_controller_test.exs +++ b/test/logflare_web/controllers/api/backend_controller_test.exs @@ -482,7 +482,7 @@ defmodule LogflareWeb.Api.BackendControllerTest do |> post("/api/backends/#{backend.token}/test") |> json_response(200) - assert response == %{"connected?" => false, "reason" => "some_reason"} + assert response == %{"connected?" => false} end test "returns 404 if backend doesn't exist or doesn't belong to user", %{ diff --git a/test/logflare_web/controllers/api/query_controller_test.exs b/test/logflare_web/controllers/api/query_controller_test.exs index b5a2a44a1f..096cb50bc0 100644 --- a/test/logflare_web/controllers/api/query_controller_test.exs +++ b/test/logflare_web/controllers/api/query_controller_test.exs @@ -74,7 +74,7 @@ defmodule LogflareWeb.Api.QueryControllerTest do assert %{"result" => [%{"my_time" => "123"}]} = response end - test "BQ errors are propagated", %{ + test "BQ errors return a generic response", %{ conn: conn, user: user } do @@ -89,7 +89,12 @@ defmodule LogflareWeb.Api.QueryControllerTest do |> get(~p"/api/query?#{[bq_sql: ~s|select current_datetime() as 'my_time'|]}") |> json_response(400) - assert %{"error" => %{"message" => "some error"}} = response + assert %{ + "error" => + "Backend error! Retry your query. Please contact support if this continues." + } = response + + refute inspect(response) =~ "some error" end end diff --git a/test/logflare_web/controllers/endpoints_controller_test.exs b/test/logflare_web/controllers/endpoints_controller_test.exs index efe7d60c20..c84cb097d3 100644 --- a/test/logflare_web/controllers/endpoints_controller_test.exs +++ b/test/logflare_web/controllers/endpoints_controller_test.exs @@ -10,6 +10,7 @@ defmodule LogflareWeb.EndpointsControllerTest do alias Logflare.Sources alias Logflare.Sources.Source alias Logflare.SystemMetrics.AllLogsLogged + alias LogflareWeb.QueryErrorHelpers setup do start_supervised!(AllLogsLogged) @@ -30,7 +31,7 @@ defmodule LogflareWeb.EndpointsControllerTest do pid = self() expect(BigQueryJobs, :bigquery_jobs_query, fn _conn, _proj_id, _opts -> - {:error, :failed_request} + {:error, TestUtils.gen_bq_error("failed_request")} end) conn = @@ -42,7 +43,7 @@ defmodule LogflareWeb.EndpointsControllerTest do |> json_response(200) |> assert_schema("EndpointQuery") - assert response.error == %{"message" => "failed_request"} + assert response.error == QueryErrorHelpers.generic_query_error_message() refute response.result refute conn.halted @@ -264,7 +265,7 @@ defmodule LogflareWeb.EndpointsControllerTest do |> assert_schema("EndpointQuery") assert response.error =~ - "Multiple CTEs available (first_cte, second_cte, final_data). You must specify which one to query using `f:name`" + LogflareWeb.QueryErrorHelpers.generic_query_error_message() refute response.result end @@ -387,7 +388,7 @@ defmodule LogflareWeb.EndpointsControllerTest do |> assert_schema("EndpointQuery") assert response.error =~ - "Table 'nonexistent' not found in available CTEs: first_cte, second_cte" + LogflareWeb.QueryErrorHelpers.generic_query_error_message() refute response.result end diff --git a/test/logflare_web/live/alerts/alerts_live_test.exs b/test/logflare_web/live/alerts/alerts_live_test.exs index 8923dcf0ec..2975f3d0e5 100644 --- a/test/logflare_web/live/alerts/alerts_live_test.exs +++ b/test/logflare_web/live/alerts/alerts_live_test.exs @@ -367,7 +367,10 @@ defmodule LogflareWeb.AlertsLiveTest do assert html =~ "No results from query. Alert will not fire." end - test "errors from BQ are displayed", %{conn: conn, alert_query: alert_query} do + test "unclassified BQ errors display a generic message", %{ + conn: conn, + alert_query: alert_query + } do GoogleApi.BigQuery.V2.Api.Jobs |> expect(:bigquery_jobs_query, 1, fn _conn, _proj_id, _opts -> {:error, TestUtils.gen_bq_error("some error")} @@ -375,9 +378,13 @@ defmodule LogflareWeb.AlertsLiveTest do {:ok, view, _html} = live_with_redirect(conn, ~p"/alerts/#{alert_query.id}") - assert view - |> element("button", "Run query") - |> render_click() =~ "some error" + html = + view + |> element("button", "Run query") + |> render_click() + + assert html =~ "Backend error! Retry your query. Please contact support if this continues." + refute html =~ "some error" end end @@ -400,17 +407,21 @@ defmodule LogflareWeb.AlertsLiveTest do assert view |> render() =~ ~r/1 .+ processed/ end - test "errors from BQ are dispalyed", %{conn: conn, alert_query: alert_query} do + test "missing field errors are displayed with user-facing message", %{ + conn: conn, + alert_query: alert_query + } do GoogleApi.BigQuery.V2.Api.Jobs |> expect(:bigquery_jobs_query, 1, fn _conn, _proj_id, _opts -> - {:error, TestUtils.gen_bq_error("some error")} + {:error, TestUtils.gen_bq_error("Unrecognized name: notthere at [1:8]")} end) {:ok, view, _html} = live_with_redirect(conn, ~p"/alerts/#{alert_query.id}") assert view |> element("button", "Run query") - |> render_click() =~ "some error" + |> render_click() =~ + "Field "notthere" does not exist." end test "test query from edit page uses the submitted query", %{ @@ -437,6 +448,20 @@ defmodule LogflareWeb.AlertsLiveTest do assert html =~ "edit-results" end + test "test query from edit page handles SQL validation errors", %{ + conn: conn, + alert_query: alert_query + } do + {:ok, view, _html} = live_with_redirect(conn, ~p"/alerts/#{alert_query.id}/edit") + + html = + view + |> element("form[phx-submit='run-query']") + |> render_submit(%{query: "select * from `my-source`"}) + + assert html =~ "Error when running query: restricted wildcard (*) in a result column" + end + test "test query from new page uses the submitted query", %{conn: conn} do test_query = "select current_timestamp() as test_col" diff --git a/test/logflare_web/live/backends/components_test.exs b/test/logflare_web/live/backends/components_test.exs index e4133a0ce7..878f23257a 100644 --- a/test/logflare_web/live/backends/components_test.exs +++ b/test/logflare_web/live/backends/components_test.exs @@ -16,23 +16,23 @@ defmodule LogflareWeb.Backends.ComponentsTest do refute html =~ "fa-check" end - test "renders an error icon and reason when the async result failed" do + test "renders a generic query error message when the async result failed" do result = AsyncResult.failed(AsyncResult.loading(), {:error, "boom"}) html = render_component(&Components.status_indicator/1, %{status: result}) assert html =~ "fa-times" assert html =~ "tw-text-red-500" - assert html =~ "boom" + assert html =~ "Backend error! Retry your query." refute html =~ "fa-spinner" refute html =~ "fa-check" end - test "renders a generic 'Internal error' message on non-error failure" do + test "renders a generic query error message on non-error failure" do result = AsyncResult.failed(AsyncResult.loading(), {:exit, :boom}) html = render_component(&Components.status_indicator/1, %{status: result}) assert html =~ "fa-times" - assert html =~ "Internal error" + assert html =~ "Backend error! Retry your query." refute html =~ "fa-spinner" refute html =~ "fa-check" end diff --git a/test/logflare_web/live/log_event_live_test.exs b/test/logflare_web/live/log_event_live_test.exs index ac8d57a8bc..67426d6a4e 100644 --- a/test/logflare_web/live/log_event_live_test.exs +++ b/test/logflare_web/live/log_event_live_test.exs @@ -96,7 +96,7 @@ defmodule LogflareWeb.LogEventLiveTest do le = build(:log_event, message: "some err message") expect(GoogleApi.BigQuery.V2.Api.Jobs, :bigquery_jobs_query, 1, fn _conn, _proj_id, _opts -> - {:error, "some error"} + {:error, TestUtils.gen_bq_error("Unrecognized name: notthere at [1:8]")} end) logs = @@ -115,6 +115,6 @@ defmodule LogflareWeb.LogEventLiveTest do end) assert logs =~ "Error loading log event" - assert logs =~ "some error" + assert logs =~ "Unrecognized name: notthere" end end diff --git a/test/logflare_web/live/search_live/logs_search_lv_test.exs b/test/logflare_web/live/search_live/logs_search_lv_test.exs index 0d8f2d772e..6efaeda061 100644 --- a/test/logflare_web/live/search_live/logs_search_lv_test.exs +++ b/test/logflare_web/live/search_live/logs_search_lv_test.exs @@ -8,6 +8,10 @@ defmodule LogflareWeb.Source.SearchLVTest do alias GoogleApi.BigQuery.V2.Model.TableSchema, as: TS alias GoogleApi.BigQuery.V2.Model.TableFieldSchema, as: TFS alias Logflare.Backends + alias Logflare.Backends.Adaptor.BigQueryAdaptor + alias Logflare.Backends.Adaptor.ClickHouseAdaptor + alias Logflare.Backends.Adaptor.PostgresAdaptor + alias Logflare.Backends.QueryError alias Logflare.Google.BigQuery.SchemaUtils alias Logflare.SingleTenant alias Logflare.Sources.Source.BigQuery.Schema @@ -1368,21 +1372,145 @@ defmodule LogflareWeb.Source.SearchLVTest do %{executor_pid: search_executor_pid} = get_view_assigns(view) allow_sandbox(search_executor_pid) - error_response = - %{ - error: %{ - message: - "Query exceeded limit for bytes billed: 2000000000. 20004857600 or higher required." - } - } - |> Jason.encode!() + message = + "Query exceeded limit for bytes billed: 2000000000. 20004857600 or higher required." - send(view.pid, {:search_error, %{error: %Tesla.Env{status: 400, body: error_response}}}) + send_query_error( + view, + backend: BigQueryAdaptor, + raw_error: %{ + "message" => message, + "reason" => "billingTierLimitExceeded" + } + ) assert render(view) =~ "Query halted: total bytes processed for this query is expected to be greater than 2 GB" end + test "shows user-facing error for backend missing field errors", %{ + conn: conn, + source: source + } do + assert {:ok, view, _html} = + live_with_redirect( + conn, + Routes.live_path(conn, SearchLV, source, querystring: "t:20022") + ) + + %{executor_pid: search_executor_pid} = get_view_assigns(view) + allow_sandbox(search_executor_pid) + + message = "Unrecognized name: notthere at [1:8]" + + send_query_error( + view, + backend: BigQueryAdaptor, + raw_error: %{"message" => message} + ) + + assert render(view) =~ + "Query halted: Field "notthere" does not exist." + end + + test "shows user-facing error for BigQuery nested missing field errors", %{ + conn: conn, + source: source + } do + assert {:ok, view, _html} = + live_with_redirect( + conn, + Routes.live_path(conn, SearchLV, source, querystring: "t:20022") + ) + + %{executor_pid: search_executor_pid} = get_view_assigns(view) + allow_sandbox(search_executor_pid) + + message = "Field name nonexistent does not exist in STRUCT at [1:42]" + + send_query_error( + view, + backend: BigQueryAdaptor, + raw_error: %{"message" => message} + ) + + assert render(view) =~ + "Query halted: Field "nonexistent" does not exist." + end + + test "shows user-facing error for ClickHouse missing field errors", %{ + conn: conn, + source: source + } do + assert {:ok, view, _html} = + live_with_redirect( + conn, + Routes.live_path(conn, SearchLV, source, querystring: "t:20022") + ) + + %{executor_pid: search_executor_pid} = get_view_assigns(view) + allow_sandbox(search_executor_pid) + + message = + "Code: 47. DB::Exception: Unknown expression identifier `notthere` in scope SELECT notthere. (UNKNOWN_IDENTIFIER) (version 26.2.19.43 (official build))\n" + + send_query_error( + view, + backend: ClickHouseAdaptor, + raw_error: %Ch.Error{message: message} + ) + + assert render(view) =~ + "Query halted: Field "notthere" does not exist." + end + + test "shows user-facing error for Postgres missing field errors", %{ + conn: conn, + source: source + } do + assert {:ok, view, _html} = + live_with_redirect( + conn, + Routes.live_path(conn, SearchLV, source, querystring: "t:20022") + ) + + %{executor_pid: search_executor_pid} = get_view_assigns(view) + allow_sandbox(search_executor_pid) + + send_query_error( + view, + backend: PostgresAdaptor, + raw_error: %Postgrex.Error{message: ~s|column "notthere" does not exist|} + ) + + assert render(view) =~ + "Query halted: Field "notthere" does not exist." + end + + test "shows generic backend error for unclassified query errors", %{ + conn: conn, + source: source + } do + assert {:ok, view, _html} = + live_with_redirect( + conn, + Routes.live_path(conn, SearchLV, source, querystring: "t:20022") + ) + + %{executor_pid: search_executor_pid} = get_view_assigns(view) + allow_sandbox(search_executor_pid) + + send_query_error( + view, + backend: BigQueryAdaptor, + raw_error: %RuntimeError{message: "raw backend syntax error"}, + description: nil + ) + + assert render(view) =~ + "Backend error! Retry your query. Please contact support if this continues." + end + test "redirected for non-owner user", %{conn: conn, source: source} do non_owner_user = insert(:user) non_owner_team = insert(:team, user: non_owner_user) @@ -2281,6 +2409,13 @@ defmodule LogflareWeb.Source.SearchLVTest do end end + defp send_query_error(view, attrs) do + attrs = Keyword.put_new(attrs, :kind, :invalid_query) + error = struct!(QueryError, attrs) + + send(view.pid, {:search_error, %{error: error}}) + end + defp wait_for_search_completed(prev_completed_at, timeout \\ 2_000) do receive do {:wait_for_render, %{last_query_completed_at: completed_at}} diff --git a/test/logflare_web/live_views/endpoints_live_test.exs b/test/logflare_web/live_views/endpoints_live_test.exs index 3da048b704..45dd96e12d 100644 --- a/test/logflare_web/live_views/endpoints_live_test.exs +++ b/test/logflare_web/live_views/endpoints_live_test.exs @@ -485,6 +485,32 @@ defmodule LogflareWeb.EndpointsLiveTest do end end + describe "run query errors" do + test "backend errors display a generic message", %{conn: conn, user: user} do + endpoint = insert(:endpoint, user: user, query: "select current_datetime() as ts") + + GoogleApi.BigQuery.V2.Api.Jobs + |> expect(:bigquery_jobs_query, 1, fn _conn, _proj_id, _opts -> + {:error, TestUtils.gen_bq_error("raw backend detail", reason: "backendError")} + end) + + {:ok, view, _html} = live_with_redirect(conn, "/endpoints/#{endpoint.id}") + + html = + view + |> element("form", "Test query") + |> render_submit(%{ + run: %{ + query: endpoint.query, + params: %{} + } + }) + + assert html =~ LogflareWeb.QueryErrorHelpers.generic_query_error_message() + refute html =~ "raw backend detail" + end + end + defp change_editor_query(view, query) do result = view diff --git a/test/logflare_web/live_views/query_live_test.exs b/test/logflare_web/live_views/query_live_test.exs index 6d0efa5b3e..0d5c81284a 100644 --- a/test/logflare_web/live_views/query_live_test.exs +++ b/test/logflare_web/live_views/query_live_test.exs @@ -89,6 +89,25 @@ defmodule LogflareWeb.QueryLiveTest do assert render(view) =~ "some-data" end + test "backend errors display a generic message", %{conn: conn} do + GoogleApi.BigQuery.V2.Api.Jobs + |> expect(:bigquery_jobs_query, 1, fn _conn, _proj_id, _opts -> + {:error, TestUtils.gen_bq_error("raw backend detail", reason: "backendError")} + end) + + {:ok, view, _html} = live_with_redirect(conn, ~p"/query") + + view + |> render_hook("parse-query", %{ + value: "select current_timestamp() as ts" + }) + + html = submit_query_form(view, conn) + + assert html =~ LogflareWeb.QueryErrorHelpers.generic_query_error_message() + refute html =~ "raw backend detail" + end + test "parser error", %{conn: conn} do {:ok, view, _html} = live_with_redirect(conn, ~p"/query") diff --git a/test/logflare_web/query_error_helpers_test.exs b/test/logflare_web/query_error_helpers_test.exs new file mode 100644 index 0000000000..fa7a1aff4a --- /dev/null +++ b/test/logflare_web/query_error_helpers_test.exs @@ -0,0 +1,127 @@ +defmodule LogflareWeb.QueryErrorHelpersTest do + use ExUnit.Case, async: true + + alias Logflare.Backends.Adaptor.BigQueryAdaptor + alias Logflare.Backends.Adaptor.ClickHouseAdaptor + alias Logflare.Backends.Adaptor.PostgresAdaptor + alias Logflare.Backends.QueryError + alias LogflareWeb.QueryErrorHelpers + + doctest LogflareWeb.QueryErrorHelpers + + describe "query_error_message/1" do + test "returns a generic message for unclassified BigQuery errors" do + error = + query_error( + backend: BigQueryAdaptor, + raw_error: %RuntimeError{message: "raw backend syntax error near SELECT secret_field"} + ) + + message = QueryErrorHelpers.query_error_message(error) + + assert message == QueryErrorHelpers.generic_query_error_message() + refute message =~ "secret_field" + refute message =~ "raw backend" + end + + test "returns a generic message for unclassified ClickHouse errors" do + error = + query_error( + backend: ClickHouseAdaptor, + raw_error: %{message: "backend internal detail"} + ) + + assert QueryErrorHelpers.query_error_message(error) == + QueryErrorHelpers.generic_query_error_message() + end + + test "returns a generic message for unclassified Postgres errors" do + error = + query_error( + backend: PostgresAdaptor, + raw_error: %{message: "backend internal detail"} + ) + + assert QueryErrorHelpers.query_error_message(error) == + QueryErrorHelpers.generic_query_error_message() + end + + test "returns missing field message for classified query errors" do + error = + query_error( + backend: BigQueryAdaptor, + raw_error: %{"message" => "Unrecognized name: notthere at [1:8]"} + ) + + assert QueryErrorHelpers.query_error_message(error) == + ~s(Field "notthere" does not exist.) + end + + test "returns BigQuery query without FROM clause invalid query message" do + error = + query_error( + backend: BigQueryAdaptor, + raw_error: %{ + "code" => 400, + "errors" => [ + %{ + "domain" => "global", + "location" => "q", + "locationType" => "parameter", + "message" => "Query without FROM clause cannot have a WHERE clause at [1:47]", + "reason" => "invalidQuery" + } + ], + "message" => "Query without FROM clause cannot have a WHERE clause at [1:47]", + "status" => "INVALID_ARGUMENT" + } + ) + + assert QueryErrorHelpers.query_error_message(error) == + "Query without FROM clause cannot have a WHERE clause at [1:47]" + end + + test "returns bytes billed limit message for classified query errors" do + error = + query_error( + backend: BigQueryAdaptor, + raw_error: %{ + "message" => + "Query exceeded limit for bytes billed: 2000000000. 20004857600 or higher required.", + "reason" => "billingTierLimitExceeded" + } + ) + + assert QueryErrorHelpers.query_error_message(error) == + "total bytes processed for this query is expected to be greater than 2 GB" + end + + test "falls back to generic message when bytes billed parsing fails" do + error = + query_error( + backend: BigQueryAdaptor, + raw_error: %{ + "message" => + "Query exceeded limit for bytes billed but no numeric limit was returned", + "reason" => "billingTierLimitExceeded" + } + ) + + assert QueryErrorHelpers.query_error_message(error) == + QueryErrorHelpers.generic_query_error_message() + end + end + + defp query_error(attrs) do + attrs = + Keyword.merge( + [ + kind: :invalid_query, + description: nil + ], + attrs + ) + + struct!(QueryError, attrs) + end +end diff --git a/test/support/test_utils.ex b/test/support/test_utils.ex index 96cad047a2..56b9ab84f6 100644 --- a/test/support/test_utils.ex +++ b/test/support/test_utils.ex @@ -148,10 +148,15 @@ defmodule Logflare.TestUtils do end) ``` """ - def gen_bq_error(err) do + def gen_bq_error(err, attrs \\ []) do + error = + attrs + |> Enum.into(%{}, fn {key, value} -> {to_string(key), value} end) + |> Map.put("message", err) + %Tesla.Env{ status: 400, - body: Jason.encode!(%{error: %{message: err}}) + body: Jason.encode!(%{error: error}) } end