Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Allow configuring stacktrace for logging #658

Open
wants to merge 17 commits into
base: master
Choose a base branch
from

Conversation

v0idpwn
Copy link
Member

@v0idpwn v0idpwn commented Mar 27, 2025

Click to expand old description A lot of times, more stack items can be helpful in identifying the source of a query.

This PR demonstrates how we can support it. But the API has problems:

  1. the :stacktrace option is used not only by logging but also for general telemetry events. Making it an integer doesn't make sense for telemetry (as the full stacktrace is published there anyway).

  2. the :stacktrace option is overriden Ecto-side, so Ecto.SQL can't accept integers on a per-query basis, only on global configuration.

Adds a new option :log_stacktrace_mfa that can be used at configuration level or query level (like :log, or :stacktrace). This config allows filtering/prepping the stacktrace-derived data displayed in the logs. For example, one may want to filter other modules other than those that Ecto.SQL filters by default, or maybe just include more stack items.

Sample usage:

# Using a custom function
config :my_app, MyApp.Repo, stacktrace: true, log_stacktrace_mfa: {MyApp.Utils, :prepare_ecto_stacktrace, []}

# Using the default one, with an increased stacktrace size to 3
config :my_app, MyApp.Repo, stacktrace: true, log_stacktrace_mfa: {Ecto.Adapters.SQL, :first_non_ecto_stacktrace, [3]}

v0idpwn added 3 commits March 27, 2025 14:36
A lot of times, more stack items can be helpful in identifying the
source of a query.

This commit demonstrates how we can support it. But the API has
problems:

1. the `:stacktrace` option is used not only by logging but also
for general telemetry events. Making it an integer doesn't make sense for
telemetry (as the full stacktrace is published there anyway).

2. the `:stacktrace` option is overriden Ecto-side, so Ecto.SQL can't
accept integers on a per-query basis, only on global configuration.
Left the alternative `last_non_ecto` implementation taking a parameter
for length. Goal is to make it easier to just increase the length
without needing to implement a new function or use a 3rd party
package.
@v0idpwn v0idpwn changed the title Allow configuring stacktrace depth for logging Allow configuring stacktrace for logging Mar 28, 2025
@v0idpwn v0idpwn force-pushed the feat/stacktrace-depth branch from 6ee7ee5 to 80e5eb8 Compare March 28, 2025 22:17
@v0idpwn v0idpwn marked this pull request as ready for review March 28, 2025 23:21
@v0idpwn
Copy link
Member Author

v0idpwn commented Mar 29, 2025

@josevalim Pushed all your suggestions, thanks for the thorough review!

Only one thing: EctoSQL integration CI is running on v1.11.4 (this is the oldest supported version as well). Enum.with_index support for functions was added only afterwards. I will push another commit removing the need for it, but we should consider bumping CI. Specially because Ecto already requires v1.14.

Edit: I decided to just bump CI elixir version :)

@v0idpwn v0idpwn force-pushed the feat/stacktrace-depth branch from 07ecdf5 to f833e9a Compare March 29, 2025 16:57
@v0idpwn v0idpwn requested a review from greg-rychlewski March 29, 2025 19:15
@@ -1377,21 +1425,29 @@ defmodule Ecto.Adapters.SQL do

@repo_modules [Ecto.Repo.Queryable, Ecto.Repo.Schema, Ecto.Repo.Transaction]

defp last_non_ecto([{mod, _, _, _} | _stacktrace], repo, last)
def first_non_ecto_stacktrace(stacktrace, repo, size) do
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We need to document this function. But also document the new option in Ecto. But this function could have a full example of how to configure it and use it :)

Copy link
Member

@josevalim josevalim left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

One last comment and ship it!

@v0idpwn v0idpwn force-pushed the feat/stacktrace-depth branch from 0ea86d4 to da99c79 Compare March 30, 2025 17:25
with [_ | _] <- stacktrace,
{module, function, arity, info} <- last_non_ecto(Enum.reverse(stacktrace), repo, nil) do
defp log_stacktrace([_ | _] = stacktrace, repo, {module, function, args}) do
entries = apply(module, function, [stacktrace, repo | args])
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
entries = apply(module, function, [stacktrace, repo | args])
entries = apply(module, function, [stacktrace, %{repo: repo} | args])

As per the Ecto issue.

Comment on lines +1438 to +1440
|> Enum.reverse()
|> last_non_ecto_entries(repo, [])
|> Enum.take(size)
Copy link
Member

@greg-rychlewski greg-rychlewski Mar 31, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not sure how big these stacktraces can get. Is it better to pass a decrementing counter to last_non_ecto_entries and reverse at the end? Or it doesn't really matter?

Co-authored-by: Greg Rychlewski <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants