diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml new file mode 100644 index 0000000..1993140 --- /dev/null +++ b/.github/workflows/ci.yml @@ -0,0 +1,44 @@ +name: CI + +on: + push: + branches: [master] + pull_request: + branches: [master] + +jobs: + test: + runs-on: ubuntu-latest + + strategy: + matrix: + elixir: ['1.17'] + otp: ['27'] + + steps: + - uses: actions/checkout@v4 + + - name: Set up Elixir + uses: erlef/setup-beam@v1 + with: + elixir-version: ${{ matrix.elixir }} + otp-version: ${{ matrix.otp }} + + - name: Restore deps cache + uses: actions/cache@v4 + with: + path: deps + key: ${{ runner.os }}-mix-${{ hashFiles('**/mix.lock') }} + restore-keys: ${{ runner.os }}-mix- + + - name: Install dependencies + run: mix deps.get + + - name: Check formatting + run: mix format --check-formatted + + - name: Compile with warnings as errors + run: mix compile --warnings-as-errors + + - name: Run tests + run: mix test diff --git a/.github/workflows/release.yml b/.github/workflows/release.yml new file mode 100644 index 0000000..54462e8 --- /dev/null +++ b/.github/workflows/release.yml @@ -0,0 +1,101 @@ +name: Release + +on: + push: + tags: + - 'v*' + +jobs: + test: + runs-on: ubuntu-latest + + strategy: + matrix: + elixir: ['1.17'] + otp: ['27'] + + steps: + - uses: actions/checkout@v4 + + - name: Set up Elixir + uses: erlef/setup-beam@v1 + with: + elixir-version: ${{ matrix.elixir }} + otp-version: ${{ matrix.otp }} + + - name: Restore deps cache + uses: actions/cache@v4 + with: + path: deps + key: ${{ runner.os }}-mix-${{ hashFiles('**/mix.lock') }} + restore-keys: ${{ runner.os }}-mix- + + - name: Install dependencies + run: mix deps.get + + - name: Compile + run: mix compile --warnings-as-errors + + - name: Run tests + run: mix test + + publish: + needs: test + runs-on: ubuntu-latest + + permissions: + contents: write + + steps: + - uses: actions/checkout@v4 + + - name: Set up Elixir + uses: erlef/setup-beam@v1 + with: + elixir-version: '1.17' + otp-version: '27' + + - name: Restore deps cache + uses: actions/cache@v4 + with: + path: deps + key: ${{ runner.os }}-mix-${{ hashFiles('**/mix.lock') }} + restore-keys: ${{ runner.os }}-mix- + + - name: Install dependencies + run: mix deps.get + + - name: Verify tag matches mix.exs version + run: | + TAG_VERSION="${GITHUB_REF_NAME#v}" + MIX_VERSION=$(grep 'version:' mix.exs | head -1 | sed 's/.*"\(.*\)".*/\1/') + echo "Tag version: $TAG_VERSION" + echo "Mix version: $MIX_VERSION" + if [ "$TAG_VERSION" != "$MIX_VERSION" ]; then + echo "::error::Tag version ($TAG_VERSION) does not match mix.exs version ($MIX_VERSION)" + exit 1 + fi + + - name: Publish to Hex.pm + run: mix hex.publish --yes + env: + HEX_API_KEY: ${{ secrets.HEX_API_KEY }} + + - name: Create GitHub Release + env: + GH_TOKEN: ${{ github.token }} + run: | + TAG="${GITHUB_REF_NAME}" + VERSION="${TAG#v}" + + # Detect pre-release from version string (rc, alpha, beta, dev) + if echo "$VERSION" | grep -qE '[-](rc|alpha|beta|dev)'; then + PRERELEASE="--prerelease" + else + PRERELEASE="" + fi + + gh release create "$TAG" \ + --title "$TAG" \ + --generate-notes \ + $PRERELEASE diff --git a/.travis.yml b/.travis.yml deleted file mode 100644 index e02d868..0000000 --- a/.travis.yml +++ /dev/null @@ -1,41 +0,0 @@ -language: elixir -elixir: - - 1.4 - - 1.5 - - 1.6 - - 1.7 - - 1.8 - - 1.9 -otp_release: - - 19.3 - - 20.3 - - 21.3 -env: - - STRICT=true - - STRICT=false -matrix: - exclude: - - elixir: 1.4 - env: STRICT=true - - elixir: 1.5 - env: STRICT=true - - elixir: 1.6 - env: STRICT=true - - elixir: 1.7 - env: STRICT=true - - elixir: 1.8 - env: STRICT=true - - elixir: 1.9 - env: STRICT=false - - elixir: 1.4 - otp_release: 21.3 - - elixir: 1.5 - otp_release: 21.3 - - elixir: 1.8 - otp_release: 19.3 - - elixir: 1.9 - otp_release: 19.3 -script: - - if [ "$STRICT" = "true" ]; then mix compile --warnings-as-errors; fi - - mix test - - if [ "$STRICT" = "true" ]; then mix format --dry-run --check-formatted; fi diff --git a/CHANGELOG.md b/CHANGELOG.md index 7a13dfb..8b04e9f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,51 @@ # master +# 2.0.0 + +* New Features + * Error Monitoring — Automatic capture of unhandled exceptions in Phoenix controllers via telemetry. Errors are reported to Scout with full stacktraces, request context, and filtered parameters. Configure with `errors_enabled`, `errors_ignored_exceptions`, and `errors_filter_parameters`. + * Log Management — OTLP-based log forwarding to Scout. Integrates with Elixir's Logger via a custom handler. Supports batched delivery, severity mapping, and automatic context extraction. Configure with `logs_enabled`, `logs_endpoint`, `logs_ingest_key`, `logs_level`, and `logs_filter_modules`. + * External Services (Finch) — Automatic instrumentation of outbound HTTP calls via Finch (and Req) using `:telemetry`. Captures method, URL, status code, and duration. + * External Services (Tesla) — Automatic instrumentation of outbound HTTP calls via Tesla using `:telemetry`. Captures method, URL, status code, and duration. + * LiveView Telemetry — Automatic instrumentation of Phoenix LiveView `mount`, `handle_event`, and `handle_params` callbacks. + * Oban Telemetry — Automatic instrumentation of Oban background job execution. Jobs appear as `Job` type spans. + * HEEx Engine — Template render instrumentation for `.heex` templates (Phoenix 1.6+). + * Database Metrics — Ecto spans now include `db.command` and `db.rows` tags for richer database visibility. + * Metadata Capture — Improved application metadata reporting including Elixir version, loaded libraries, hostname, and git SHA. + +* Enhancements + * Update Core Agent to v1.5.0 (from v1.2.6) + * Update telemetry dependency to `~> 1.0` (from `~> 0.3.0 or ~> 0.4.0`) + * Phoenix, phoenix_html, and phoenix_live_view are now optional dependencies (enables compile-time HEEx instrumentation) + * Ecto logger extracts SQL command type and row counts from query results + * Better core agent lifecycle handling (already-running detection, config file path support) + * Default checkin host updated to `checkin.scoutapm.com` + +* New Configuration Options + * `errors_enabled` (default: `true`) — Enable/disable error capture + * `errors_host` (default: `https://errors.scoutapm.com`) — Error reporting endpoint + * `errors_batch_size` (default: `5`) — Errors per batch + * `errors_max_queue_size` (default: `500`) — Max queued errors + * `errors_flush_interval_ms` (default: `1000`) — Error flush interval + * `errors_ignored_exceptions` (default: `[]`) — Exception modules to ignore + * `errors_filter_parameters` (default: `[]`) — Parameter keys to redact + * `logs_enabled` (default: `false`) — Enable/disable log forwarding + * `logs_endpoint` (default: `https://otlp.scoutotel.com:4318`) — OTLP log endpoint + * `logs_ingest_key` (default: `nil`) — Ingest API key for log forwarding + * `logs_batch_size` (default: `100`) — Logs per batch + * `logs_max_queue_size` (default: `5000`) — Max queued logs + * `logs_flush_interval_ms` (default: `5000`) — Log flush interval + * `logs_level` (default: `:info`) — Minimum log level to forward + * `logs_filter_modules` (default: `[]`) — Logger modules to exclude + * `log_level` (default: `:info`) — Scout agent's own log level + +* Breaking Changes + * Elixir >= 1.14 required (was 1.4) + * Telemetry `~> 1.0` required (was `~> 0.3.0 or ~> 0.4.0`) + * Phoenix `~> 1.6` (optional, was `~> 1.0`) + * Removed `phoenix_slime` dependency + * Removed `credo` dependency + # 1.0.7 * Enhancements diff --git a/README.md b/README.md index 9030457..77ac62b 100644 --- a/README.md +++ b/README.md @@ -1,7 +1,7 @@ # Scout Elixir Performance Monitoring Agent `scout_apm` monitors the performance of Elixir applications in production and provides an in-browser profiler during development. Metrics are -reported to [Scout](https://scoutapp.com), a hosted application monitoring service. +reported to [Scout](https://scoutapm.com), a hosted application monitoring service. ![screenshot](https://s3-us-west-1.amazonaws.com/scout-blog/elixir_screenshot.png) @@ -33,3 +33,257 @@ config :scout_apm, ## Instrumentation See [our docs](http://docs.scoutapm.com/#elixir-instrumented-libaries) for information on libraries we auto-instrument (like Phoenix controller-actions) and guides for instrumenting Phoenix channels, Task, HTTPoison, GenServer, and more. + +### Supported Template Engines + +Scout APM automatically instruments the following Phoenix template engines: + +- **EEx** (`.eex`) - Standard Embedded Elixir templates +- **ExS** (`.exs`) - ExScript templates +- **HEEx** (`.heex`) - HTML-aware Embedded Elixir (requires `phoenix_live_view ~> 0.17`) +- **Slime** (`.slim`, `.slime`) - Slim-like templates (requires `phoenix_slime`) + +Template engines are enabled automatically based on your project's dependencies. To use Scout's instrumented engines, add to your `config/config.exs`: + +```elixir +config :phoenix, :template_engines, + eex: ScoutApm.Instruments.EExEngine, + exs: ScoutApm.Instruments.ExsEngine, + heex: ScoutApm.Instruments.HEExEngine # Only if phoenix_live_view is installed +``` + +## Error Tracking + +Scout APM captures errors automatically and allows manual error capture. + +### Automatic Error Capture + +Errors are automatically captured from: +- Phoenix controller exceptions (via telemetry) +- LiveView exceptions (mount, handle_event, handle_params) +- Oban job failures +- Code wrapped in `transaction` blocks + +To enable Phoenix router-level error capture, add to your application startup: + +```elixir +# In your application.ex start/2 +def start(_type, _args) do + ScoutApm.Instruments.PhoenixErrorTelemetry.attach() + # ... rest of supervision tree +end +``` + +### Manual Error Capture + +Capture errors manually with `ScoutApm.Error.capture/2`: + +```elixir +try do + risky_operation() +rescue + e -> + ScoutApm.Error.capture(e, stacktrace: __STACKTRACE__) + reraise e, __STACKTRACE__ +end +``` + +With additional context: + +```elixir +ScoutApm.Error.capture(exception, + stacktrace: __STACKTRACE__, + context: %{user_id: user.id}, + request_path: conn.request_path, + request_params: conn.params +) +``` + +### Configuration + +```elixir +config :scout_apm, + # Enable/disable error capture (default: true) + errors_enabled: true, + + # Exceptions to ignore (default: []) + errors_ignored_exceptions: [Phoenix.Router.NoRouteError], + + # Additional parameter keys to filter (default: []) + # Built-in: password, token, secret, api_key, auth, credentials, etc. + errors_filter_parameters: ["credit_card", "cvv"] +``` + +## OTLP Logging + +Scout APM can capture Elixir Logger messages, enrich them with request context, and send them to an OpenTelemetry collector via OTLP (OpenTelemetry Protocol). + +### Setup + +1. Enable logging in your configuration: + +```elixir +# config/config.exs +config :scout_apm, + logs_enabled: true, + logs_ingest_key: "your-logs-ingest-key" # Or falls back to :key +``` + +2. Attach the log handler in your application startup: + +```elixir +# In your application.ex start/2 +def start(_type, _args) do + ScoutApm.Logging.attach() + # ... rest of supervision tree +end +``` + +### Automatic Context Enrichment + +Logs captured within Scout-tracked requests are automatically enriched with: + +- `scout_transaction_id` - Unique request identifier for correlation +- `controller_entrypoint` - Controller action name (e.g., "UsersController#show") +- `job_entrypoint` - Background job name (e.g., "Job/EmailWorker") +- `scout_current_operation` - Current span type/name (e.g., "Ecto/MyApp.Repo") +- `scout_start_time` - Request start time (ISO 8601) +- `scout_end_time` - Request end time, if completed +- `scout_duration` - Request duration in seconds, if completed +- `scout_tag_{key}` - Custom tags from `ScoutApm.Context.add/2` +- `user.{key}` - User context from `ScoutApm.Context.add_user/2` +- `service.name` - Application name from config + +Entrypoint and transaction ID attributes persist through the entire request lifecycle, including logs emitted after the Scout transaction completes (e.g., Phoenix endpoint logs). + +Example - logs are automatically enriched when inside a Scout-tracked request: + +```elixir +def show(conn, %{"id" => id}) do + user = Repo.get!(User, id) + Logger.info("Fetched user", user_id: id) # Includes Scout context automatically + render(conn, :show, user: user) +end +``` + +### Custom Context + +Add custom context that appears in your logs: + +```elixir +ScoutApm.Context.add("feature_flag", "new_checkout") +ScoutApm.Context.add_user("id", current_user.id) + +Logger.info("Processing checkout") # Includes scout_tag_feature_flag and user.id +``` + +### Configuration + +```elixir +config :scout_apm, + # Enable/disable log capture (default: false, opt-in) + logs_enabled: true, + + # OTLP collector endpoint + logs_endpoint: "https://otlp.scoutotel.com:4318", + + # Authentication key (falls back to :key if not set) + logs_ingest_key: "your-logs-key", + + # Minimum log level to capture (default: :info) + logs_level: :info, + + # Batching settings + logs_batch_size: 100, # Logs per batch (default: 100) + logs_max_queue_size: 5000, # Max queued logs (default: 5000) + logs_flush_interval_ms: 5_000, # Flush interval in ms (default: 5000) + + # Modules to exclude from capture (default: []) + logs_filter_modules: [MyApp.VerboseModule] +``` + +### Programmatic Control + +```elixir +# Attach with custom options +ScoutApm.Logging.attach(level: :warning, filter_modules: [MyApp.Noisy]) + +# Check if attached +ScoutApm.Logging.attached?() # => true + +# Force flush queued logs +ScoutApm.Logging.flush() + +# Wait for queue to drain (useful for graceful shutdown) +ScoutApm.Logging.drain(5_000) + +# Detach the handler +ScoutApm.Logging.detach() +``` + +### Log Levels + +The following Elixir log levels are mapped to OTLP severity: + +| Elixir Level | OTLP Severity | OTLP Number | +|--------------|---------------|-------------| +| `:debug` | DEBUG | 5 | +| `:info` | INFO | 9 | +| `:notice` | INFO2 | 11 | +| `:warning` | WARN | 13 | +| `:error` | ERROR | 17 | +| `:critical` | FATAL | 21 | +| `:alert` | FATAL | 21 | +| `:emergency` | FATAL | 21 | + +## Development + +See [TESTING.md](TESTING.md) for information on testing with different template engine configurations. + +## Releasing + +Releases are published to [Hex.pm](https://hex.pm/packages/scout_apm) automatically via GitHub Actions when a version tag is pushed. + +### Standard Release + +1. Update the version in `mix.exs`: + ```elixir + version: "2.0.0", + ``` + +2. Commit the version bump: + ```bash + git commit -am "Bump version to 2.0.0" + ``` + +3. Tag and push: + ```bash + git tag v2.0.0 + git push origin v2.0.0 + ``` + +The workflow will run tests, verify the tag matches `mix.exs`, publish to Hex.pm, and create a GitHub Release. + +### Pre-release / RC Version + +Use Elixir's pre-release version format. The tag must match `mix.exs` exactly. + +1. Update `mix.exs`: + ```elixir + version: "2.0.0-rc.1", + ``` + +2. Tag and push: + ```bash + git tag v2.0.0-rc.1 + git push origin v2.0.0-rc.1 + ``` + +Pre-release versions (tags containing `-rc`, `-alpha`, `-beta`, or `-dev`) are automatically marked as pre-release on GitHub. On Hex.pm, pre-release versions are not installed by default -- users must opt in with `{:scout_apm, "~> 2.0.0-rc.1"}`. + +### Requirements + +- A `HEX_API_KEY` secret must be configured in the repository settings. Generate one with: + ```bash + mix hex.user key generate --key-name github-actions + ``` diff --git a/TESTING.md b/TESTING.md new file mode 100644 index 0000000..adb04d6 --- /dev/null +++ b/TESTING.md @@ -0,0 +1,61 @@ +# Testing Scout APM + +Scout APM supports multiple Phoenix template engines through conditional compilation: +- **EEx** (`.eex`) - Standard Embedded Elixir templates +- **ExS** (`.exs`) - ExScript templates +- **HEEx** (`.heex`) - HTML-aware Embedded Elixir (Phoenix LiveView) + +## Running Tests + +```bash +mix deps.get +mix test +``` + +## Template Engine Tests + +All template engine modules use conditional compilation via `Code.ensure_loaded?/1`: + +```elixir +if Code.ensure_loaded?(Phoenix.LiveView.HTMLEngine) do + defmodule ScoutApm.Instruments.HEExEngine do + # ... only compiled when phoenix_live_view is available + end +end +``` + +This means: +- Engines are only compiled when their dependencies are available +- Users only install the template engines they actually use +- No runtime errors for missing optional dependencies +- Scout APM "just works" with whatever template engines the user has installed + +### Running Specific Template Engine Tests + +```bash +# Test HEEx engine +mix test test/scout_apm/instruments/heex_engine_test.exs + +# Test EEx engine +mix test test/scout_apm/instruments/eex_engine_test.exs + +# Test ExS engine +mix test test/scout_apm/instruments/exs_engine_test.exs +``` + +## User Configuration + +Users of Scout APM add template engines to their `config/config.exs`: + +```elixir +config :phoenix, :template_engines, + eex: ScoutApm.Instruments.EExEngine, + exs: ScoutApm.Instruments.ExsEngine, + heex: ScoutApm.Instruments.HEExEngine # Only if phoenix_live_view is installed +``` + +The appropriate engines are automatically available based on the user's dependencies. + +## CI + +Tests run on GitHub Actions with the latest Elixir and OTP versions. See `.github/workflows/ci.yml` for configuration. diff --git a/config/test.exs b/config/test.exs index 2ff402b..664b32c 100644 --- a/config/test.exs +++ b/config/test.exs @@ -1,6 +1,6 @@ import Config -config :logger, backends: [] +config :logger, :default_handler, false config :scout_apm, collector_module: ScoutApm.TestCollector diff --git a/lib/scout_apm/application.ex b/lib/scout_apm/application.ex index f353b00..6964546 100644 --- a/lib/scout_apm/application.ex +++ b/lib/scout_apm/application.ex @@ -3,13 +3,38 @@ defmodule ScoutApm.Application do use Application + @config_keys [ + :name, + :key, + :hostname, + :monitor, + :log_level, + :core_agent_launch, + :core_agent_download, + :core_agent_dir, + :core_agent_version, + :core_agent_tcp_ip, + :core_agent_tcp_port, + :core_agent_log_level, + :core_agent_log_file, + :core_agent_config_file, + :errors_enabled, + :errors_host, + :logs_enabled, + :logs_endpoint + ] + def start(_type, _args) do collector_module = ScoutApm.Config.find(:collector_module) children = [ ScoutApm.PersistentHistogram, - Supervisor.child_spec({ScoutApm.Watcher, ScoutApm.PersistentHistogram}, id: :histogram_watcher), - collector_module + Supervisor.child_spec({ScoutApm.Watcher, ScoutApm.PersistentHistogram}, + id: :histogram_watcher + ), + collector_module, + ScoutApm.Error.ErrorService, + ScoutApm.Logging.LogService ] ScoutApm.Cache.setup() @@ -21,7 +46,18 @@ defmodule ScoutApm.Application do ScoutApm.Watcher.start_link(ScoutApm.Supervisor) + log_config() ScoutApm.Logger.log(:info, "ScoutAPM Started") {:ok, pid} end + + defp log_config do + config_values = + @config_keys + |> Enum.map(fn key -> {key, ScoutApm.Config.find(key)} end) + |> Enum.map(fn {key, value} -> " #{key}: #{inspect(value)}" end) + |> Enum.join("\n") + + ScoutApm.Logger.log(:debug, "ScoutAPM Configuration:\n#{config_values}") + end end diff --git a/lib/scout_apm/commands.ex b/lib/scout_apm/commands.ex index baa6ef8..bbf1154 100644 --- a/lib/scout_apm/commands.ex +++ b/lib/scout_apm/commands.ex @@ -137,19 +137,20 @@ defmodule ScoutApm.Command.ApplicationEvent do event_type: "scout.metadata", event_value: %{ language: "elixir", + language_version: language_version(), version: System.version(), server_time: "#{NaiveDateTime.to_iso8601(NaiveDateTime.utc_now())}Z", - framework: "", - framework_version: "", + framework: detect_framework(), + framework_version: detect_framework_version(), environment: "", - app_server: "", + app_server: detect_app_server(), hostname: ScoutApm.Cache.hostname(), database_engine: "", - database_adapter: "", + database_adapter: detect_database_adapter(), application_name: ScoutApm.Config.find(:name), libraries: libraries(), paas: "", - application_root: "", + application_root: application_root(), git_sha: ScoutApm.Cache.git_sha() }, source: inspect(self()) @@ -162,9 +163,77 @@ defmodule ScoutApm.Command.ApplicationEvent do fn {name, _desc, version} -> [to_string(name), to_string(version)] end ) end + + defp language_version do + otp_release = :erlang.system_info(:otp_release) |> to_string() + erts_version = :erlang.system_info(:version) |> to_string() + "#{System.version()} (OTP #{otp_release}, ERTS #{erts_version})" + end + + defp detect_framework do + cond do + app_loaded?(:phoenix) -> "Phoenix" + app_loaded?(:plug) -> "Plug" + true -> "" + end + end + + defp detect_framework_version do + cond do + app_loaded?(:phoenix) -> app_version(:phoenix) + app_loaded?(:plug) -> app_version(:plug) + true -> "" + end + end + + defp detect_app_server do + cond do + app_loaded?(:bandit) -> "Bandit" + app_loaded?(:cowboy) -> "Cowboy" + true -> "" + end + end + + defp detect_database_adapter do + adapters = [ + {:postgrex, "PostgreSQL"}, + {:myxql, "MySQL"}, + {:tds, "MSSQL"}, + {:exqlite, "SQLite"}, + {:ecto_sqlite3, "SQLite"} + ] + + adapters + |> Enum.find(fn {app, _name} -> app_loaded?(app) end) + |> case do + {_app, name} -> name + nil -> "" + end + end + + defp application_root do + case File.cwd() do + {:ok, cwd} -> cwd + _ -> "" + end + end + + defp app_loaded?(app) do + Application.loaded_applications() + |> Enum.any?(fn {name, _desc, _version} -> name == app end) + end + + defp app_version(app) do + Application.loaded_applications() + |> Enum.find(fn {name, _desc, _version} -> name == app end) + |> case do + {_name, _desc, version} -> to_string(version) + nil -> "" + end + end end -defimpl ScoutApm.Command, for: ScoutApm.Command.ApplicationEvent do +defimpl ScoutApm.Command, for: ScoutApm.Command.ApplicationEvent do def message(%Command.ApplicationEvent{} = event) do %{ ApplicationEvent: %{ @@ -301,10 +370,11 @@ defmodule ScoutApm.Command.Batch do defp operation(%Layer{type: "Ecto"}), do: "SQL/Query" defp operation(%Layer{type: "EEx"}), do: "Template/Render" defp operation(%Layer{type: "Exs"}), do: "Template/Render" + defp operation(%Layer{type: "HTTP"} = layer), do: "HTTP/#{layer.name}" defp operation(layer), do: "#{layer.type}/#{layer.name}" defp tag_spans(%Layer{type: "Ecto"} = layer, request_id, span_id) do - [ + base_tags = [ %Command.TagSpan{ timestamp: layer.started_at, request_id: request_id, @@ -313,6 +383,38 @@ defmodule ScoutApm.Command.Batch do value: layer.desc } ] + + rows_tag = + if layer.db_rows do + [ + %Command.TagSpan{ + timestamp: layer.started_at, + request_id: request_id, + span_id: span_id, + tag: "db.rows_returned", + value: to_string(layer.db_rows) + } + ] + else + [] + end + + op_tag = + if layer.db_command do + [ + %Command.TagSpan{ + timestamp: layer.started_at, + request_id: request_id, + span_id: span_id, + tag: "db.operation", + value: layer.db_command + } + ] + else + [] + end + + base_tags ++ rows_tag ++ op_tag end defp tag_spans(%Layer{type: type} = layer, request_id, span_id) when type in ["EEx", "Exs"] do @@ -327,6 +429,49 @@ defmodule ScoutApm.Command.Batch do ] end + defp tag_spans(%Layer{type: "HTTP"} = layer, request_id, span_id) do + # Send "url" tag for core agent domain extraction (it looks for "uri" then "url") + # Keep "http.url" for any downstream consumers that may depend on it + url_tags = + if layer.http_url do + [ + %Command.TagSpan{ + timestamp: layer.started_at, + request_id: request_id, + span_id: span_id, + tag: "url", + value: layer.http_url + }, + %Command.TagSpan{ + timestamp: layer.started_at, + request_id: request_id, + span_id: span_id, + tag: "http.url", + value: layer.http_url + } + ] + else + [] + end + + status_tag = + if layer.http_status_code do + [ + %Command.TagSpan{ + timestamp: layer.started_at, + request_id: request_id, + span_id: span_id, + tag: "http.status_code", + value: to_string(layer.http_status_code) + } + ] + else + [] + end + + url_tags ++ status_tag + end + defp tag_spans(_layer, _request_id, _span_id), do: [] end diff --git a/lib/scout_apm/config.ex b/lib/scout_apm/config.ex index 27e20c5..8d1e41f 100644 --- a/lib/scout_apm/config.ex +++ b/lib/scout_apm/config.ex @@ -37,6 +37,13 @@ defmodule ScoutApm.Config do end defp coercion(:monitor), do: &Coercions.boolean/1 + defp coercion(:core_agent_launch), do: &Coercions.boolean/1 + defp coercion(:core_agent_download), do: &Coercions.boolean/1 + defp coercion(:dev_trace), do: &Coercions.boolean/1 + defp coercion(:errors_enabled), do: &Coercions.boolean/1 + defp coercion(:logs_enabled), do: &Coercions.boolean/1 + defp coercion(:log_level), do: &Coercions.log_level/1 + defp coercion(:logs_level), do: &Coercions.log_level/1 defp coercion(:ignore), do: &Coercions.json/1 defp coercion(_), do: fn x -> {:ok, x} end end diff --git a/lib/scout_apm/config/coercions.ex b/lib/scout_apm/config/coercions.ex index f19563d..7726dc1 100644 --- a/lib/scout_apm/config/coercions.ex +++ b/lib/scout_apm/config/coercions.ex @@ -37,4 +37,16 @@ defmodule ScoutApm.Config.Coercions do end def json(_), do: :error + + @valid_log_levels [:debug, :info, :warn, :warning, :error] + def log_level(level) when is_atom(level) and level in @valid_log_levels, do: {:ok, level} + + def log_level(level) when is_binary(level) do + atom_level = String.to_existing_atom(String.downcase(level)) + log_level(atom_level) + rescue + ArgumentError -> :error + end + + def log_level(_), do: :error end diff --git a/lib/scout_apm/config/defaults.ex b/lib/scout_apm/config/defaults.ex index 3c6dce2..45dd878 100644 --- a/lib/scout_apm/config/defaults.ex +++ b/lib/scout_apm/config/defaults.ex @@ -1,20 +1,38 @@ defmodule ScoutApm.Config.Defaults do def load do %{ - host: "https://checkin.scoutapp.com", + host: "https://checkin.scoutapm.com", direct_host: "https://apm.scoutapp.com", dev_trace: false, + log_level: :info, monitor: true, ignore: [], core_agent_dir: "/tmp/scout_apm_core", core_agent_download: true, core_agent_launch: true, - core_agent_version: "v1.2.6", + core_agent_version: "v1.5.1", core_agent_tcp_ip: {127, 0, 0, 1}, core_agent_tcp_port: 9000, collector_module: ScoutApm.Core.AgentManager, download_url: - "https://s3-us-west-1.amazonaws.com/scout-public-downloads/apm_core_agent/release" + "https://s3-us-west-1.amazonaws.com/scout-public-downloads/apm_core_agent/release", + # Error tracking configuration + errors_enabled: true, + errors_host: "https://errors.scoutapm.com", + errors_batch_size: 5, + errors_max_queue_size: 500, + errors_flush_interval_ms: 1_000, + errors_ignored_exceptions: [], + errors_filter_parameters: [], + # OTLP Logging configuration + logs_enabled: false, + logs_endpoint: "https://otlp.scoutotel.com:4318", + logs_ingest_key: nil, + logs_batch_size: 100, + logs_max_queue_size: 5000, + logs_flush_interval_ms: 5_000, + logs_level: :info, + logs_filter_modules: [] } end diff --git a/lib/scout_apm/core.ex b/lib/scout_apm/core.ex index 1e51679..bcc6e93 100644 --- a/lib/scout_apm/core.ex +++ b/lib/scout_apm/core.ex @@ -39,9 +39,16 @@ defmodule ScoutApm.Core do @spec platform_triple :: String.t() def platform_triple do - "#{architecture()}-#{platform()}" + triple = "#{architecture()}-#{platform()}" + # For Apple Silicon (M1/M2/M3), use x86_64 binary via Rosetta 2 + # since there's no native ARM build of the Core Agent. + # See https://github.com/scoutapp/scout_apm_python/issues/683 + apple_darwin_aarch64_override(triple) end + defp apple_darwin_aarch64_override("aarch64-apple-darwin"), do: "x86_64-apple-darwin" + defp apple_darwin_aarch64_override(triple), do: triple + @spec platform :: String.t() def platform do case :os.type() do @@ -62,7 +69,9 @@ defmodule ScoutApm.Core do case uname_architecture() do "x86_64" -> "x86_64" "i686" -> "i686" - _ -> "unknown" + "arm64" -> "aarch64" + "aarch64" -> "aarch64" + other -> other end end diff --git a/lib/scout_apm/core/agent_manager.ex b/lib/scout_apm/core/agent_manager.ex index d2fce2f..a2948e8 100644 --- a/lib/scout_apm/core/agent_manager.ex +++ b/lib/scout_apm/core/agent_manager.ex @@ -4,10 +4,37 @@ defmodule ScoutApm.Core.AgentManager do alias ScoutApm.Core.Manifest @behaviour ScoutApm.Collector - defstruct [:socket] + # TCP recv/send timeout in milliseconds (matches Python agent's 3s) + @tcp_timeout 3_000 + + # Maximum queued messages before dropping (Python agent uses 500) + @max_queue_size 500 + + # Consecutive errors before attempting reconnect + @max_errors_before_reconnect 3 + + # Consecutive reconnect failures before restarting the core agent process + @max_reconnect_failures 5 + + # Backoff schedule for reconnection attempts (milliseconds) + @reconnect_backoff_ms [100, 500, 1_000, 1_000, 5_000] + + defstruct [ + :socket, + :port, + error_count: 0, + reconnect_failures: 0, + last_reconnect_at: nil, + reconnecting: false + ] @type t :: %__MODULE__{ - socket: :gen_tcp.socket() | nil + socket: :gen_tcp.socket() | nil, + port: port() | nil, + error_count: non_neg_integer(), + reconnect_failures: non_neg_integer(), + last_reconnect_at: integer() | nil, + reconnecting: boolean() } def start_link(_) do @@ -18,15 +45,16 @@ defmodule ScoutApm.Core.AgentManager do @impl GenServer @spec init(any) :: {:ok, t()} def init(_) do + Process.flag(:trap_exit, true) start_setup() - {:ok, %__MODULE__{socket: nil}} + {:ok, %__MODULE__{}} end def start_setup do GenServer.cast(__MODULE__, :setup) end - @spec setup :: :gen_tcp.socket() | nil + @spec setup :: {port() | nil, :gen_tcp.socket() | nil} def setup do enabled = ScoutApm.Config.find(:monitor) core_agent_launch = ScoutApm.Config.find(:core_agent_launch) @@ -35,16 +63,22 @@ defmodule ScoutApm.Core.AgentManager do if enabled && core_agent_launch && key do with {:ok, manifest} <- verify_or_download(), bin_path when is_binary(bin_path) <- Manifest.bin_path(manifest), - {:ok, socket} <- run(bin_path) do - register() - app_metadata() - socket + {:ok, port_or_nil, socket} <- run(bin_path) do + # Send Register and app_metadata directly on the socket, not via cast. + # setup() runs inside handle_cast(:setup), so any cast from here goes to + # the back of the mailbox. If app requests arrive before those casts are + # processed, a BatchCommand hits the core agent before Register, and the + # core agent rejects it as an unregistered client. + state = %__MODULE__{socket: socket, port: port_or_nil} + state = send_register(state) + state = send_app_metadata(state) + {state.port, state.socket} else _e -> - nil + {nil, nil} end else - nil + {nil, nil} end end @@ -63,12 +97,12 @@ defmodule ScoutApm.Core.AgentManager do {:ok, manifest} else _ -> - ScoutApm.Logger.log(:warn, "Failed to start ScoutApm Core Agent") + ScoutApm.Logger.log(:error, "Failed to start ScoutApm Core Agent") {:error, :failed_to_start} end else ScoutApm.Logger.log( - :warn, + :info, "Not attempting to download ScoutApm Core Agent due to :core_agent_download configuration" ) @@ -79,6 +113,7 @@ defmodule ScoutApm.Core.AgentManager do @spec download_binary(String.t(), String.t(), String.t()) :: :ok | {:error, any()} def download_binary(url, directory, file_name) do destination = Path.join([directory, file_name]) + ScoutApm.Logger.log(:info, "Attempting to download ScoutApm Core Agent from: #{url}") with :ok <- File.mkdir_p(directory), {:ok, 200, _headers, client_ref} <- :hackney.get(url, [], "", follow_redirect: true), @@ -90,8 +125,8 @@ defmodule ScoutApm.Core.AgentManager do else e -> ScoutApm.Logger.log( - :warn, - "Failed to download and extract ScoutApm Core Agent: #{inspect(e)}" + :error, + "Failed to download and extract ScoutApm Core Agent from #{url}: #{inspect(e)}" ) {:error, :failed_to_download_and_extract} @@ -100,18 +135,28 @@ defmodule ScoutApm.Core.AgentManager do @impl ScoutApm.Collector def send(message) when is_map(message) do - GenServer.cast(__MODULE__, {:send, message}) + # Check the GenServer's mailbox size from the caller's process BEFORE + # casting. This prevents messages from accumulating in the mailbox while + # the GenServer is blocked on TCP or reconnection. The internal check + # in handle_cast is a second line of defense. + case GenServer.whereis(__MODULE__) do + nil -> + :ok + + pid -> + case Process.info(pid, :message_queue_len) do + {:message_queue_len, len} when len > @max_queue_size -> + :ok + + _ -> + GenServer.cast(__MODULE__, {:send, message}) + end + end end - def app_metadata do - message = - ScoutApm.Command.ApplicationEvent.app_metadata() - |> ScoutApm.Command.message() + defp send_register(%{socket: nil} = state), do: state - send(message) - end - - def register do + defp send_register(state) do name = ScoutApm.Config.find(:name) key = ScoutApm.Config.find(:key) hostname = ScoutApm.Config.find(:hostname) @@ -119,36 +164,68 @@ defmodule ScoutApm.Core.AgentManager do message = ScoutApm.Command.message(%ScoutApm.Command.Register{app: name, key: key, host: hostname}) - send(message) + send_message(message, state) + end + + defp send_app_metadata(%{socket: nil} = state), do: state + + defp send_app_metadata(state) do + message = + ScoutApm.Command.ApplicationEvent.app_metadata() + |> ScoutApm.Command.message() + + send_message(message, state) end @impl GenServer @spec handle_cast(any, t()) :: {:noreply, t()} def handle_cast(:setup, state) do - {:noreply, %{state | socket: setup()}} + {port, socket} = setup() + {:noreply, %{state | port: port, socket: socket}} + end + + @impl GenServer + def handle_cast({:send, _message}, %{socket: nil, reconnecting: true} = state) do + # Reconnect already scheduled, just drop the message + {:noreply, state} end @impl GenServer def handle_cast({:send, _message}, %{socket: nil} = state) do - ScoutApm.Logger.log( - :warn, - "ScoutApm Core Agent is not connected. Skipping sending event." - ) + state = maybe_reconnect(state) + + if state.socket == nil do + ScoutApm.Logger.log( + :debug, + "ScoutApm Core Agent is not connected. Skipping sending event." + ) + end {:noreply, state} end @impl GenServer def handle_cast({:send, message}, state) when is_map(message) do - state = send_message(message, state) - {:noreply, state} + case Process.info(self(), :message_queue_len) do + {:message_queue_len, len} when len > @max_queue_size -> + ScoutApm.Logger.log( + :error, + "ScoutApm message queue full (#{len} > #{@max_queue_size}), dropping message" + ) + + {:noreply, state} + + _ -> + state = send_message(message, state) + {:noreply, state} + end end @impl GenServer @spec handle_call(any, any(), t()) :: {:reply, any, t()} def handle_call({:send, _message}, _from, %{socket: nil} = state) do ScoutApm.Logger.log( - :warn, + :error, "ScoutApm Core Agent is not connected. Skipping sending event." ) @@ -163,10 +240,75 @@ defmodule ScoutApm.Core.AgentManager do @impl GenServer @spec handle_info(any, t()) :: {:noreply, t()} + def handle_info({port, {:exit_status, status}}, %{port: port} = state) do + ScoutApm.Logger.log( + :error, + "ScoutApm Core Agent exited with status #{status}" + ) + + {:noreply, %{state | port: nil, socket: nil}} + end + + def handle_info({port, {:data, _data}}, %{port: port} = state) do + # Discard stdout/stderr data from the core agent + {:noreply, state} + end + + def handle_info(:do_full_restart, state) do + ScoutApm.Logger.log(:info, "Launching new ScoutApm Core Agent after restart delay") + {port, socket} = setup() + now = System.monotonic_time(:millisecond) + + if socket do + {:noreply, + %{ + state + | port: port, + socket: socket, + error_count: 0, + reconnect_failures: 0, + reconnecting: false, + last_reconnect_at: now + }} + else + {:noreply, + %{ + state + | port: port, + socket: nil, + reconnect_failures: state.reconnect_failures + 1, + reconnecting: false, + last_reconnect_at: now + }} + end + end + def handle_info(_m, state) do {:noreply, state} end + @impl GenServer + def terminate(_reason, %{port: port} = state) do + if port != nil do + ScoutApm.Logger.log(:info, "Shutting down ScoutApm Core Agent") + close_port(port) + end + + if state.socket != nil do + :gen_tcp.close(state.socket) + end + + :ok + end + + defp close_port(port) do + try do + Port.close(port) + rescue + ArgumentError -> :ok + end + end + @spec pad_leading(binary(), integer(), integer()) :: binary() def pad_leading(binary, len, byte \\ 0) @@ -180,28 +322,162 @@ defmodule ScoutApm.Core.AgentManager do (<> |> :binary.copy(len - byte_size(binary))) <> binary end - @spec run(String.t()) :: {:ok, :gen_tcp.socket()} | nil + @spec run(String.t()) :: {:ok, port() | nil, :gen_tcp.socket()} | nil def run(bin_path) do ip = ScoutApm.Config.find(:core_agent_tcp_ip) |> :inet_parse.ntoa() - port = ScoutApm.Config.find(:core_agent_tcp_port) + tcp_port = ScoutApm.Config.find(:core_agent_tcp_port) socket_path = Core.socket_path() - args = ["start", "--socket", socket_path, "--daemonize", "true", "--tcp", "#{ip}:#{port}"] + args = [ + "start", + "--socket", + socket_path, + "--daemonize", + "false", + "--tcp", + "#{ip}:#{tcp_port}" + ] - with {_, 0} <- System.cmd(bin_path, args), - {:ok, socket} <- try_connect_twice(ip, port) do - {:ok, socket} - else - e -> + args = + args + |> maybe_add_log_level() + |> maybe_add_log_file() + |> maybe_add_config_file() + + ScoutApm.Logger.log(:debug, "Starting Core Agent: #{bin_path} #{Enum.join(args, " ")}") + + port = launch_core_agent(bin_path, args) + + # Give the core agent time to start listening, then check if + # the launched process exited quickly (e.g. already running). + Process.sleep(500) + port = drain_port_exit(port) + + case try_connect(socket_path, ip, tcp_port) do + {:ok, socket} -> + {:ok, port, socket} + + nil -> + ScoutApm.Logger.log(:error, "Unable to connect to ScoutApm Core Agent") + + if port do + close_port(port) + end + + nil + end + end + + # Launch the core agent through a shell wrapper that monitors stdin. + # When the BEAM exits for ANY reason (graceful shutdown, ctrl-c abort, + # crash), the stdin pipe closes, `cat` returns, and the wrapper kills + # the core agent. This ensures cleanup even when terminate/2 is skipped. + defp launch_core_agent(bin_path, args) do + shell_cmd = Enum.map_join([bin_path | args], " ", &shell_escape/1) + + # When stdin closes (BEAM exit or close_port): send SIGTERM, wait up to 5s, + # then SIGKILL if the process is still alive (e.g. frozen by SIGSTOP). + wrapper = + ~s(#{shell_cmd} & PID=$!; cat > /dev/null; kill $PID 2>/dev/null; for i in 1 2 3 4 5; do kill -0 $PID 2>/dev/null || exit 0; sleep 1; done; kill -9 $PID 2>/dev/null; wait $PID 2>/dev/null) + + Port.open({:spawn_executable, ~c"/bin/sh"}, [ + :binary, + :exit_status, + :stderr_to_stdout, + :use_stdio, + args: ["-c", wrapper] + ]) + rescue + e -> + ScoutApm.Logger.log( + :error, + "Unable to start ScoutApm Core Agent: #{inspect(e)}" + ) + + nil + end + + defp shell_escape(arg) do + "'" <> String.replace(arg, "'", "'\\''") <> "'" + end + + # Check if the port process already exited. If so, consume the + # exit_status message so it doesn't trigger handle_info later, + # and return nil (we don't own the running agent). + defp drain_port_exit(nil), do: nil + + defp drain_port_exit(port) do + receive do + {^port, {:exit_status, _status}} -> ScoutApm.Logger.log( - :warn, - "Unable to start and connect to ScoutApm Core Agent: #{inspect(e)}" + :debug, + "Core Agent process exited quickly (likely already running)" ) nil + + {^port, {:data, _data}} -> + drain_port_exit(port) + after + 0 -> port + end + end + + @spec try_connect(String.t(), charlist(), char()) :: {:ok, :gen_tcp.socket()} | nil + defp try_connect(socket_path, ip, port) do + case try_connect_socket(socket_path) do + {:ok, socket} -> + ScoutApm.Logger.log(:debug, "Connected to Core Agent via Unix socket") + {:ok, socket} + + {:error, socket_reason} -> + ScoutApm.Logger.log( + :debug, + "Unix socket connection failed (#{inspect(socket_reason)}), trying TCP" + ) + + case try_connect_tcp(ip, port) do + {:ok, socket} -> + ScoutApm.Logger.log(:debug, "Connected to Core Agent via TCP") + {:ok, socket} + + {:error, tcp_reason} -> + ScoutApm.Logger.log( + :error, + "Unable to connect to ScoutApm Core Agent via socket (#{inspect(socket_reason)}) or TCP (#{inspect(tcp_reason)})" + ) + + nil + end + end + end + + @socket_opts [{:active, false}, :binary, {:send_timeout, @tcp_timeout}] + + @spec try_connect_socket(String.t()) :: {:ok, :gen_tcp.socket()} | {:error, atom()} + defp try_connect_socket(socket_path) do + case :gen_tcp.connect({:local, socket_path}, 0, @socket_opts) do + {:ok, socket} -> + {:ok, socket} + + _ -> + :timer.sleep(500) + :gen_tcp.connect({:local, socket_path}, 0, @socket_opts) + end + end + + @spec try_connect_tcp(charlist(), char()) :: {:ok, :gen_tcp.socket()} | {:error, atom()} + defp try_connect_tcp(ip, port) do + case :gen_tcp.connect(ip, port, @socket_opts) do + {:ok, socket} -> + {:ok, socket} + + _ -> + :timer.sleep(500) + :gen_tcp.connect(ip, port, @socket_opts) end end @@ -211,48 +487,185 @@ defmodule ScoutApm.Core.AgentManager do binary_length <- pad_leading(:binary.encode_unsigned(message_length, :big), 4, 0), :ok <- :gen_tcp.send(socket, binary_length), :ok <- :gen_tcp.send(socket, encoded), - {:ok, <>} <- :gen_tcp.recv(socket, 4), - {:ok, msg} <- :gen_tcp.recv(socket, message_length), + {:ok, <>} <- + :gen_tcp.recv(socket, 4, @tcp_timeout), + {:ok, msg} <- :gen_tcp.recv(socket, message_length, @tcp_timeout), {:ok, decoded_msg} <- Jason.decode(msg) do ScoutApm.Logger.log( :debug, "Received message of length #{message_length}: #{inspect(decoded_msg)}" ) - state + %{state | error_count: 0, reconnect_failures: 0} else - {:error, :closed} -> - Port.close(socket) + {:error, :timeout} -> + ScoutApm.Logger.log( + :warning, + "ScoutApm Core Agent TCP recv timed out after #{@tcp_timeout}ms" + ) + + handle_send_error(socket, state) + {:error, :closed} -> ScoutApm.Logger.log( - :warn, - "ScoutApm Core Agent TCP socket closed. Attempting to reconnect." + :error, + "ScoutApm Core Agent TCP socket closed" ) - %{state | socket: setup()} + handle_send_error(socket, state) {:error, :enotconn} -> - Port.close(socket) - ScoutApm.Logger.log( - :warn, - "ScoutApm Core Agent TCP socket disconnected. Attempting to reconnect." + :error, + "ScoutApm Core Agent TCP socket disconnected" ) - %{state | socket: setup()} + handle_send_error(socket, state) e -> - Port.close(socket) - ScoutApm.Logger.log( - :warn, - "Error in ScoutApm Core Agent TCP socket: #{inspect(e)}. Attempting to reconnect." + :error, + "Error in ScoutApm Core Agent TCP socket: #{inspect(e)}" ) - %{state | socket: setup()} + handle_send_error(socket, state) end end + defp handle_send_error(socket, state) do + :gen_tcp.close(socket) + error_count = state.error_count + 1 + state = %{state | socket: nil, error_count: error_count} + + if error_count >= @max_errors_before_reconnect do + maybe_reconnect(state) + else + ScoutApm.Logger.log( + :debug, + "ScoutApm Core Agent error #{error_count}/#{@max_errors_before_reconnect} before reconnect attempt" + ) + + state + end + end + + defp maybe_reconnect(state) do + now = System.monotonic_time(:millisecond) + + backoff_index = + min(state.reconnect_failures, length(@reconnect_backoff_ms) - 1) + + backoff = Enum.at(@reconnect_backoff_ms, backoff_index) + + # Allow immediate reconnect on first attempt (last_reconnect_at is nil) + elapsed = if state.last_reconnect_at, do: now - state.last_reconnect_at, else: backoff + + if elapsed < backoff do + ScoutApm.Logger.log( + :debug, + "ScoutApm Core Agent reconnect backing off (#{backoff}ms between attempts)" + ) + + state + else + do_reconnect(state, now) + end + end + + defp do_reconnect(state, now) do + # If we own the port and have exceeded max failures, kill the old process + # and do a full setup (launch + connect). This is done asynchronously via + # handle_info(:do_full_restart) so the GenServer stays responsive and can + # drop incoming messages instead of letting them pile up in the mailbox. + if state.port && state.reconnect_failures >= @max_reconnect_failures do + ScoutApm.Logger.log( + :error, + "Scheduling ScoutApm Core Agent restart after #{state.reconnect_failures} reconnect failures" + ) + + close_port(state.port) + # Schedule the full restart after giving the shell wrapper time to + # SIGTERM → SIGKILL the hung process and release the TCP port. + Process.send_after(self(), :do_full_restart, 6_000) + + %{state | port: nil, reconnecting: true, last_reconnect_at: now} + else + # Try to reconnect the socket only — don't launch a new process. + # The existing core agent may have recovered (e.g. SIGCONT after SIGSTOP). + ScoutApm.Logger.log( + :info, + "Attempting ScoutApm Core Agent socket reconnect (failure #{state.reconnect_failures + 1})" + ) + + case try_reconnect_socket() do + {:ok, socket} -> + # Validate the socket is actually responsive before trusting it. + # A SIGSTOP'd agent accepts TCP connections (kernel backlog) but + # never responds. We probe with Register and check the result + # directly — NOT through send_message/handle_send_error, which + # would trigger recursive reconnect logic. + case probe_socket(socket) do + :ok -> + state = %{ + state + | socket: socket, + error_count: 0, + reconnect_failures: 0, + last_reconnect_at: now + } + + send_app_metadata(state) + + :error -> + :gen_tcp.close(socket) + %{state | reconnect_failures: state.reconnect_failures + 1, last_reconnect_at: now} + end + + nil -> + %{state | reconnect_failures: state.reconnect_failures + 1, last_reconnect_at: now} + end + end + end + + # Send Register on the socket and verify we get a response. Returns :ok or :error. + # This avoids the send_message → handle_send_error → maybe_reconnect recursion. + defp probe_socket(socket) do + name = ScoutApm.Config.find(:name) + key = ScoutApm.Config.find(:key) + hostname = ScoutApm.Config.find(:hostname) + + message = + ScoutApm.Command.message(%ScoutApm.Command.Register{app: name, key: key, host: hostname}) + + with {:ok, encoded} <- Jason.encode(message), + message_length <- byte_size(encoded), + binary_length <- pad_leading(:binary.encode_unsigned(message_length, :big), 4, 0), + :ok <- :gen_tcp.send(socket, binary_length), + :ok <- :gen_tcp.send(socket, encoded), + {:ok, <>} <- + :gen_tcp.recv(socket, 4, @tcp_timeout), + {:ok, _msg} <- :gen_tcp.recv(socket, resp_len, @tcp_timeout) do + ScoutApm.Logger.log(:info, "ScoutApm Core Agent socket probe succeeded (Register accepted)") + :ok + else + _ -> + ScoutApm.Logger.log(:warning, "ScoutApm Core Agent socket probe failed (unresponsive)") + :error + end + end + + # Try to connect to an already-running core agent without launching a new one. + defp try_reconnect_socket do + ip = + ScoutApm.Config.find(:core_agent_tcp_ip) + |> :inet_parse.ntoa() + + tcp_port = ScoutApm.Config.find(:core_agent_tcp_port) + socket_path = Core.socket_path() + + try_connect(socket_path, ip, tcp_port) + end + @spec verify_or_download :: {:ok, map()} | {:error, any()} def verify_or_download do dir = ScoutApm.Config.find(:core_agent_dir) @@ -267,16 +680,38 @@ defmodule ScoutApm.Core.AgentManager do end end - @spec try_connect_twice(charlist(), char()) :: - {:ok, :gen_tcp.socket()} | {:error, atom()} - defp try_connect_twice(ip, port) do - case :gen_tcp.connect(ip, port, [{:active, false}, :binary]) do - {:ok, socket} -> - {:ok, socket} + @spec maybe_add_log_level(list(String.t())) :: list(String.t()) + defp maybe_add_log_level(args) do + case ScoutApm.Config.find(:core_agent_log_level) do + nil -> + args - _ -> - :timer.sleep(500) - :gen_tcp.connect(ip, port, [{:active, false}, :binary]) + level when is_binary(level) -> + args ++ ["--log-level", level] + end + end + + @spec maybe_add_log_file(list(String.t())) :: list(String.t()) + defp maybe_add_log_file(args) do + case ScoutApm.Config.find(:core_agent_log_file) do + nil -> + args + + path when is_binary(path) -> + expanded_path = Path.expand(path) + args ++ ["--log-file", expanded_path] + end + end + + @spec maybe_add_config_file(list(String.t())) :: list(String.t()) + defp maybe_add_config_file(args) do + case ScoutApm.Config.find(:core_agent_config_file) do + nil -> + args + + path when is_binary(path) -> + expanded_path = Path.expand(path) + args ++ ["--config-file", expanded_path] end end end diff --git a/lib/scout_apm/devtrace/plug.ex b/lib/scout_apm/devtrace/plug.ex index fb0b0e5..be6f14b 100644 --- a/lib/scout_apm/devtrace/plug.ex +++ b/lib/scout_apm/devtrace/plug.ex @@ -69,9 +69,7 @@ defmodule ScoutApm.DevTrace.Plug do defp body_tags do """ - + """ end diff --git a/lib/scout_apm/error.ex b/lib/scout_apm/error.ex new file mode 100644 index 0000000..542309a --- /dev/null +++ b/lib/scout_apm/error.ex @@ -0,0 +1,165 @@ +defmodule ScoutApm.Error do + @moduledoc """ + Public API for capturing errors in Scout APM. + + Errors can be captured manually using `capture/1` or `capture/2`, or + automatically via Phoenix telemetry handlers. + + ## Manual Error Capture + + try do + some_risky_operation() + rescue + e -> + ScoutApm.Error.capture(e, stacktrace: __STACKTRACE__) + reraise e, __STACKTRACE__ + end + + ## With Additional Context + + try do + process_user_request(user) + rescue + e -> + ScoutApm.Error.capture(e, + stacktrace: __STACKTRACE__, + context: %{user_id: user.id}, + request_path: "/api/users", + request_params: %{action: "update"} + ) + reraise e, __STACKTRACE__ + end + + ## Configuration + + Error capture can be configured in your config: + + config :scout_apm, + errors_enabled: true, + errors_ignored_exceptions: [Phoenix.Router.NoRouteError], + errors_filter_parameters: ["credit_card", "cvv"] + + ## Options + + All capture functions accept these options: + + * `:stacktrace` - The exception stacktrace. For best results, pass `__STACKTRACE__` + from within a rescue block. + * `:context` - A map of additional context to include with the error. + * `:request_path` - The request path (e.g., "/api/users"). + * `:request_params` - A map of request parameters. + * `:session` - A map of session data. + * `:custom_controller` - Override the controller name. + * `:custom_params` - A map of custom parameters. + """ + + alias ScoutApm.Error.ErrorData + alias ScoutApm.Error.ErrorService + + @type capture_opts :: [ + stacktrace: Exception.stacktrace(), + context: map(), + request_path: String.t(), + request_params: map(), + session: map(), + custom_controller: String.t(), + custom_params: map() + ] + + @doc """ + Captures an exception and sends it to Scout APM. + + The stacktrace will be captured automatically if not provided, but for + best results, pass `__STACKTRACE__` from within a rescue block. + + Returns `:ok` on success. + + ## Examples + + try do + do_something_risky() + rescue + e -> + ScoutApm.Error.capture(e, stacktrace: __STACKTRACE__) + reraise e, __STACKTRACE__ + end + + # With additional context + ScoutApm.Error.capture(exception, + stacktrace: __STACKTRACE__, + context: %{user_id: 123}, + request_path: conn.request_path + ) + """ + @spec capture(Exception.t(), capture_opts()) :: :ok + def capture(exception, opts \\ []) when is_exception(exception) do + if errors_enabled?() and not ignored_exception?(exception) do + error_data = ErrorData.from_exception(exception, opts) + ErrorService.send(error_data) + end + + :ok + end + + @doc """ + Captures an error from kind/reason/stacktrace tuple (as received in + telemetry exception events). + + This is primarily used internally by telemetry handlers but can be called + directly when handling exceptions in catch blocks. + + ## Examples + + try do + do_something() + catch + kind, reason -> + ScoutApm.Error.capture_from_telemetry(kind, reason, __STACKTRACE__) + :erlang.raise(kind, reason, __STACKTRACE__) + end + """ + @spec capture_from_telemetry( + kind :: :error | :throw | :exit, + reason :: term(), + stacktrace :: Exception.stacktrace(), + capture_opts() + ) :: :ok + def capture_from_telemetry(kind, reason, stacktrace, opts \\ []) do + if errors_enabled?() do + error_data = ErrorData.from_telemetry(kind, reason, stacktrace, opts) + + if error_data && not ignored_exception_class?(error_data.exception_class) do + ErrorService.send(error_data) + end + end + + :ok + end + + @doc """ + Returns whether error capture is currently enabled. + """ + @spec enabled?() :: boolean() + def enabled? do + errors_enabled?() + end + + defp errors_enabled? do + ScoutApm.Config.find(:errors_enabled) != false and + ScoutApm.Config.find(:monitor) == true + end + + defp ignored_exception?(exception) do + ignored = ScoutApm.Config.find(:errors_ignored_exceptions) || [] + Enum.any?(ignored, fn mod -> is_struct(exception, mod) end) + end + + defp ignored_exception_class?(class_name) do + ignored = ScoutApm.Config.find(:errors_ignored_exceptions) || [] + + Enum.any?(ignored, fn mod -> + mod_name = Module.split(mod) |> List.last() + mod_name == class_name + end) + end +end diff --git a/lib/scout_apm/error/error_data.ex b/lib/scout_apm/error/error_data.ex new file mode 100644 index 0000000..783ef88 --- /dev/null +++ b/lib/scout_apm/error/error_data.ex @@ -0,0 +1,264 @@ +defmodule ScoutApm.Error.ErrorData do + @moduledoc """ + Internal representation of an error to be sent to Scout APM. + Matches the Python agent's error data structure for backend compatibility. + """ + + alias ScoutApm.Error.ParameterFilter + + defstruct [ + :exception_class, + :message, + :request_id, + :request_uri, + :request_params, + :request_session, + :environment, + :trace, + :request_components, + :context, + :host, + :revision_sha + ] + + @type t :: %__MODULE__{ + exception_class: String.t(), + message: String.t(), + request_id: String.t() | nil, + request_uri: String.t() | nil, + request_params: map() | nil, + request_session: map() | nil, + environment: map() | nil, + trace: [String.t()], + request_components: map() | nil, + context: map(), + host: String.t() | nil, + revision_sha: String.t() | nil + } + + @doc """ + Creates an ErrorData struct from an Elixir exception. + """ + @spec from_exception(Exception.t(), keyword()) :: t() + def from_exception(exception, opts \\ []) do + stacktrace = Keyword.get(opts, :stacktrace) || get_current_stacktrace() + + %__MODULE__{ + exception_class: exception_class_name(exception), + message: Exception.message(exception), + request_id: get_request_id(), + request_uri: Keyword.get(opts, :request_path), + request_params: opts |> Keyword.get(:request_params) |> ParameterFilter.filter(), + request_session: opts |> Keyword.get(:session) |> ParameterFilter.filter(), + environment: opts |> Keyword.get(:environment) |> ParameterFilter.filter(), + trace: format_stacktrace(stacktrace), + request_components: build_request_components(opts), + context: build_context(opts), + host: ScoutApm.Cache.hostname(), + revision_sha: ScoutApm.Cache.git_sha() + } + end + + @doc """ + Creates an ErrorData struct from telemetry exception data. + """ + @spec from_telemetry(:error | :throw | :exit, term(), Exception.stacktrace(), keyword()) :: + t() | nil + def from_telemetry(:error, reason, stacktrace, opts) when is_exception(reason) do + from_exception(reason, Keyword.put(opts, :stacktrace, stacktrace)) + end + + def from_telemetry(:error, reason, stacktrace, opts) do + %__MODULE__{ + exception_class: "ErlangError", + message: inspect(reason, limit: 500), + request_id: get_request_id(), + request_uri: Keyword.get(opts, :request_path), + request_params: opts |> Keyword.get(:request_params) |> ParameterFilter.filter(), + request_session: opts |> Keyword.get(:session) |> ParameterFilter.filter(), + environment: nil, + trace: format_stacktrace(stacktrace), + request_components: build_request_components(opts), + context: build_context(opts), + host: ScoutApm.Cache.hostname(), + revision_sha: ScoutApm.Cache.git_sha() + } + end + + def from_telemetry(:throw, reason, stacktrace, opts) do + %__MODULE__{ + exception_class: "ThrowError", + message: inspect(reason, limit: 500), + request_id: get_request_id(), + request_uri: Keyword.get(opts, :request_path), + request_params: opts |> Keyword.get(:request_params) |> ParameterFilter.filter(), + request_session: opts |> Keyword.get(:session) |> ParameterFilter.filter(), + environment: nil, + trace: format_stacktrace(stacktrace), + request_components: build_request_components(opts), + context: build_context(opts), + host: ScoutApm.Cache.hostname(), + revision_sha: ScoutApm.Cache.git_sha() + } + end + + def from_telemetry(:exit, reason, stacktrace, opts) do + %__MODULE__{ + exception_class: "ExitError", + message: inspect(reason, limit: 500), + request_id: get_request_id(), + request_uri: Keyword.get(opts, :request_path), + request_params: opts |> Keyword.get(:request_params) |> ParameterFilter.filter(), + request_session: opts |> Keyword.get(:session) |> ParameterFilter.filter(), + environment: nil, + trace: format_stacktrace(stacktrace), + request_components: build_request_components(opts), + context: build_context(opts), + host: ScoutApm.Cache.hostname(), + revision_sha: ScoutApm.Cache.git_sha() + } + end + + @doc """ + Converts the ErrorData to a map suitable for JSON encoding. + """ + @spec to_map(t()) :: map() + def to_map(%__MODULE__{} = error) do + %{ + "exception_class" => error.exception_class, + "message" => error.message, + "request_id" => error.request_id, + "request_uri" => error.request_uri, + "request_params" => error.request_params, + "request_session" => error.request_session, + "environment" => error.environment, + "trace" => error.trace, + "request_components" => error.request_components, + "context" => error.context, + "host" => error.host, + "revision_sha" => error.revision_sha + } + |> Enum.reject(fn {_k, v} -> is_nil(v) end) + |> Map.new() + end + + # Private helpers + + defp exception_class_name(exception) do + exception.__struct__ + |> Module.split() + |> List.last() + end + + defp get_request_id do + case Process.get(:scout_apm_request) do + %{id: id} -> id + _ -> ScoutApm.Utils.random_string(12) + end + end + + defp get_current_stacktrace do + {:current_stacktrace, stacktrace} = Process.info(self(), :current_stacktrace) + # Drop the first few frames that are internal to this module + Enum.drop(stacktrace, 4) + end + + defp format_stacktrace(stacktrace) do + scm_subdirectory = ScoutApm.Config.find(:scm_subdirectory) || "" + + stacktrace + # Limit to 50 frames like Python + |> Enum.take(50) + |> Enum.map(fn + {mod, fun, arity, location} when is_integer(arity) -> + file = Keyword.get(location, :file, ~c"nofile") |> to_string() + line = Keyword.get(location, :line, 0) + + file_path = + if scm_subdirectory != "", do: Path.join(scm_subdirectory, file), else: file + + "#{file_path}:#{line}:in #{inspect(mod)}.#{fun}/#{arity}" + + {mod, fun, args, location} when is_list(args) -> + file = Keyword.get(location, :file, ~c"nofile") |> to_string() + line = Keyword.get(location, :line, 0) + arity = length(args) + + file_path = + if scm_subdirectory != "", do: Path.join(scm_subdirectory, file), else: file + + "#{file_path}:#{line}:in #{inspect(mod)}.#{fun}/#{arity}" + + frame -> + Exception.format_stacktrace_entry(frame) + end) + end + + defp build_request_components(opts) do + custom_controller = Keyword.get(opts, :custom_controller) + + # Try to get from tracked request + tracked_request = Process.get(:scout_apm_request) + + cond do + custom_controller -> + %{"module" => nil, "controller" => custom_controller, "action" => nil} + + tracked_request && tracked_request.root_layer -> + parse_controller_action(tracked_request.root_layer.name) + + tracked_request && length(tracked_request.layers) > 0 -> + # Get the bottom-most layer (first in list since it's a stack) + layer = List.last(tracked_request.layers) + parse_controller_action(layer.name) + + true -> + nil + end + end + + defp parse_controller_action(nil), do: nil + + defp parse_controller_action(name) do + case String.split(name, "#", parts: 2) do + [controller, action] -> + %{"module" => nil, "controller" => controller, "action" => action} + + [controller] -> + %{"module" => nil, "controller" => controller, "action" => nil} + end + end + + defp build_context(opts) do + custom_params = Keyword.get(opts, :custom_params, %{}) + user_context = Keyword.get(opts, :context, %{}) + + # Get context from tracked request + tracked_request = Process.get(:scout_apm_request) + + request_context = + if tracked_request do + contexts_map = + tracked_request.contexts + |> Enum.map(fn %{key: k, value: v} -> {k, v} end) + |> Map.new() + + Map.put(contexts_map, "transaction_id", tracked_request.id) + else + %{} + end + + base_context = + request_context + |> Map.merge(user_context) + + # Only add custom_params if not empty + if map_size(custom_params) > 0 do + Map.put(base_context, "custom_params", custom_params) + else + base_context + end + |> Enum.reject(fn {_k, v} -> v == %{} or is_nil(v) end) + |> Map.new() + end +end diff --git a/lib/scout_apm/error/error_service.ex b/lib/scout_apm/error/error_service.ex new file mode 100644 index 0000000..cf4d849 --- /dev/null +++ b/lib/scout_apm/error/error_service.ex @@ -0,0 +1,271 @@ +defmodule ScoutApm.Error.ErrorService do + @moduledoc """ + Background GenServer that batches and sends errors to Scout APM's error endpoint. + + Implements a queue with batching (default 5 errors per batch) and a maximum + queue size (default 500) to prevent memory issues. + """ + + use GenServer + + alias ScoutApm.Error.ErrorData + + @default_batch_size 5 + @default_max_queue_size 500 + @default_flush_interval_ms 1_000 + @errors_endpoint "/apps/error.scout" + + defstruct [ + :queue, + :queue_size, + :timer_ref + ] + + @type t :: %__MODULE__{ + queue: :queue.queue(ErrorData.t()), + queue_size: non_neg_integer(), + timer_ref: reference() | nil + } + + # Client API + + def start_link(opts \\ []) do + GenServer.start_link(__MODULE__, opts, name: __MODULE__) + end + + @doc """ + Sends an error to the service for batched delivery. + Non-blocking - returns immediately. + """ + @spec send(ErrorData.t()) :: :ok + def send(%ErrorData{} = error) do + GenServer.cast(__MODULE__, {:send, error}) + end + + @doc """ + Waits for the queue to drain. Used in tests and shutdown. + """ + @spec drain(timeout :: non_neg_integer()) :: :ok | :timeout + def drain(timeout \\ 5_000) do + GenServer.call(__MODULE__, :drain, timeout) + catch + :exit, _ -> :timeout + end + + @doc """ + Forces an immediate flush of queued errors. Used in tests. + """ + @spec flush() :: :ok + def flush do + GenServer.call(__MODULE__, :flush) + end + + # Server Callbacks + + @impl GenServer + def init(_opts) do + state = %__MODULE__{ + queue: :queue.new(), + queue_size: 0, + timer_ref: nil + } + + {:ok, schedule_flush(state)} + end + + @impl GenServer + def handle_cast({:send, %ErrorData{} = error}, state) do + max_size = get_max_queue_size() + + if state.queue_size >= max_size do + ScoutApm.Logger.log(:debug, "Error queue full (#{max_size}), dropping error") + {:noreply, state} + else + new_queue = :queue.in(error, state.queue) + new_state = %{state | queue: new_queue, queue_size: state.queue_size + 1} + + # If we've hit batch size, flush immediately + if new_state.queue_size >= get_batch_size() do + {:noreply, do_flush(new_state)} + else + {:noreply, new_state} + end + end + end + + @impl GenServer + def handle_call(:drain, _from, state) do + new_state = drain_all(state) + {:reply, :ok, new_state} + end + + @impl GenServer + def handle_call(:flush, _from, state) do + new_state = do_flush(state) + {:reply, :ok, new_state} + end + + @impl GenServer + def handle_info(:flush, state) do + new_state = + state + |> do_flush() + |> schedule_flush() + + {:noreply, new_state} + end + + @impl GenServer + def handle_info(_msg, state) do + {:noreply, state} + end + + @impl GenServer + def terminate(_reason, state) do + drain_all(state) + :ok + end + + # Private Functions + + defp schedule_flush(state) do + if state.timer_ref, do: Process.cancel_timer(state.timer_ref) + + timer_ref = Process.send_after(self(), :flush, get_flush_interval()) + %{state | timer_ref: timer_ref} + end + + defp do_flush(%{queue_size: 0} = state), do: state + + defp do_flush(state) do + batch_size = get_batch_size() + + {errors, remaining_queue, remaining_size} = + dequeue_batch(state.queue, state.queue_size, batch_size) + + if length(errors) > 0 do + Task.start(fn -> send_errors(errors) end) + end + + %{state | queue: remaining_queue, queue_size: remaining_size} + end + + defp drain_all(%{queue_size: 0} = state), do: state + + defp drain_all(state) do + {errors, remaining_queue, remaining_size} = + dequeue_batch(state.queue, state.queue_size, state.queue_size) + + if length(errors) > 0 do + # Send synchronously during drain + send_errors(errors) + end + + %{state | queue: remaining_queue, queue_size: remaining_size} + end + + defp dequeue_batch(queue, queue_size, batch_size) do + count = min(batch_size, queue_size) + + {errors, new_queue} = + Enum.reduce(1..max(count, 1), {[], queue}, fn + _, {acc, q} when length(acc) >= count -> + {acc, q} + + _, {acc, q} -> + case :queue.out(q) do + {{:value, error}, new_q} -> {[error | acc], new_q} + {:empty, q} -> {acc, q} + end + end) + + {Enum.reverse(errors), new_queue, queue_size - length(errors)} + end + + defp send_errors([]), do: :ok + + defp send_errors(errors) do + payload = build_payload(errors) + + case Jason.encode(payload) do + {:ok, json} -> + compressed = :zlib.gzip(json) + do_http_send(compressed, length(errors)) + + {:error, reason} -> + ScoutApm.Logger.log(:debug, "Failed to encode error payload: #{inspect(reason)}") + end + end + + defp build_payload(errors) do + %{ + "notifier" => "scout_apm_elixir", + "environment" => get_environment(), + "root" => ScoutApm.Config.find(:application_root) || File.cwd!(), + "problems" => Enum.map(errors, &ErrorData.to_map/1) + } + end + + defp get_environment do + case ScoutApm.Config.find(:environment) do + nil -> + if function_exported?(Mix, :env, 0) do + Mix.env() |> to_string() + else + "production" + end + + env -> + to_string(env) + end + end + + defp do_http_send(body, error_count) do + url = build_url() + headers = build_headers(error_count) + + case :hackney.request(:post, url, headers, body, [:with_body]) do + {:ok, status, _headers, _body} when status < 400 -> + ScoutApm.Logger.log(:debug, "Successfully sent #{error_count} errors to Scout APM") + :ok + + {:ok, status, _headers, response_body} -> + ScoutApm.Logger.log( + :debug, + "Error sending to Scout APM errors endpoint. Status: #{status}, Body: #{inspect(response_body)}" + ) + + {:error, {:http_error, status}} + + {:error, reason} -> + ScoutApm.Logger.log(:debug, "Error sending to Scout APM: #{inspect(reason)}") + {:error, reason} + end + end + + defp build_url do + host = ScoutApm.Config.find(:errors_host) || "https://errors.scoutapm.com" + key = ScoutApm.Config.find(:key) || "" + name = ScoutApm.Config.find(:name) || "" + + query = URI.encode_query(%{"key" => key, "name" => name}) + "#{host}#{@errors_endpoint}?#{query}" + end + + defp build_headers(error_count) do + [ + {"Agent-Hostname", ScoutApm.Cache.hostname() || ""}, + {"Content-Encoding", "gzip"}, + {"Content-Type", "application/json"}, + {"X-Error-Count", to_string(error_count)} + ] + end + + defp get_batch_size, do: ScoutApm.Config.find(:errors_batch_size) || @default_batch_size + + defp get_max_queue_size, + do: ScoutApm.Config.find(:errors_max_queue_size) || @default_max_queue_size + + defp get_flush_interval, + do: ScoutApm.Config.find(:errors_flush_interval_ms) || @default_flush_interval_ms +end diff --git a/lib/scout_apm/error/parameter_filter.ex b/lib/scout_apm/error/parameter_filter.ex new file mode 100644 index 0000000..860f79b --- /dev/null +++ b/lib/scout_apm/error/parameter_filter.ex @@ -0,0 +1,83 @@ +defmodule ScoutApm.Error.ParameterFilter do + @moduledoc """ + Filters sensitive parameters from request data before sending to Scout APM. + Matches the Python agent's FILTER_PARAMETERS list. + """ + + @default_filter_parameters MapSet.new([ + "access", + "access_token", + "api_key", + "apikey", + "auth", + "auth_token", + "card[number]", + "certificate", + "credentials", + "crypt", + "key", + "mysql_pwd", + "otp", + "passwd", + "password", + "private", + "protected", + "salt", + "secret", + "secret_key", + "ssn", + "stripetoken", + "token" + ]) + + @filtered_value "[FILTERED]" + + @doc """ + Filters sensitive parameters from a map or nil value. + """ + @spec filter(map() | list() | nil) :: map() | list() | nil + def filter(nil), do: nil + def filter(params) when is_map(params), do: filter_map(params) + def filter(params) when is_list(params), do: Enum.map(params, &filter_value/1) + def filter(value), do: value + + defp filter_map(map) do + filter_params = get_filter_parameters() + + map + |> Enum.map(fn {key, value} -> + key_str = to_string(key) |> String.downcase() + + if MapSet.member?(filter_params, key_str) do + {key, @filtered_value} + else + {key, filter_value(value)} + end + end) + |> Map.new() + end + + defp filter_value(value) when is_map(value), do: filter_map(value) + defp filter_value(value) when is_list(value), do: Enum.map(value, &filter_value/1) + defp filter_value(nil), do: nil + + defp filter_value(value) do + case value do + v when is_binary(v) -> v + v when is_number(v) -> v + v when is_boolean(v) -> v + v when is_atom(v) -> Atom.to_string(v) + v -> inspect(v, limit: 100) + end + end + + defp get_filter_parameters do + custom = ScoutApm.Config.find(:errors_filter_parameters) || [] + + custom + |> Enum.map(&to_string/1) + |> Enum.map(&String.downcase/1) + |> MapSet.new() + |> MapSet.union(@default_filter_parameters) + end +end diff --git a/lib/scout_apm/instruments/ecto_logger.ex b/lib/scout_apm/instruments/ecto_logger.ex index 6f6a62b..91b6904 100644 --- a/lib/scout_apm/instruments/ecto_logger.ex +++ b/lib/scout_apm/instruments/ecto_logger.ex @@ -17,11 +17,15 @@ defmodule ScoutApm.Instruments.EctoLogger do def log(entry) do case query_time_log_entry(entry) do {:ok, duration} -> + {command, num_rows} = extract_result_info(entry) + ScoutApm.TrackedRequest.track_layer( "Ecto", query_name_log_entry(entry), duration, - desc: Map.get(entry, :query) + desc: Map.get(entry, :query), + db_command: command, + db_rows: num_rows ) {:error, _} -> @@ -34,11 +38,15 @@ defmodule ScoutApm.Instruments.EctoLogger do def record(value, metadata) do case query_time(value, metadata) do {:ok, duration} -> + {command, num_rows} = extract_result_info(metadata) + ScoutApm.TrackedRequest.track_layer( "Ecto", query_name(value, metadata), duration, - desc: Map.get(metadata, :query) + desc: Map.get(metadata, :query), + db_command: command, + db_rows: num_rows ) {:error, _} -> @@ -95,4 +103,23 @@ defmodule ScoutApm.Instruments.EctoLogger do def query_time_log_entry(_entry) do {:error, :non_integer_query_time} end + + @doc false + def extract_result_info(%{result: {:ok, result}}) do + command = Map.get(result, :command) + num_rows = Map.get(result, :num_rows) + {normalize_command(command), num_rows} + end + + def extract_result_info(_), do: {nil, nil} + + defp normalize_command(:select), do: "Select" + defp normalize_command(:insert), do: "Insert" + defp normalize_command(:update), do: "Update" + defp normalize_command(:delete), do: "Delete" + + defp normalize_command(cmd) when is_atom(cmd) and not is_nil(cmd), + do: cmd |> to_string() |> String.capitalize() + + defp normalize_command(_), do: nil end diff --git a/lib/scout_apm/instruments/finch_telemetry.ex b/lib/scout_apm/instruments/finch_telemetry.ex new file mode 100644 index 0000000..94a2ebe --- /dev/null +++ b/lib/scout_apm/instruments/finch_telemetry.ex @@ -0,0 +1,167 @@ +if Code.ensure_loaded?(Telemetry) || Code.ensure_loaded?(:telemetry) do + defmodule ScoutApm.Instruments.FinchTelemetry do + @moduledoc """ + Telemetry handler for Finch HTTP client instrumentation. + + Attaches to Finch telemetry events to track external HTTP requests: + - HTTP requests appear as "HTTP" type layers (External Services) + - Tracks URL, HTTP method, and response status code + + ## Usage + + In your application's `start/2` function: + + def start(_type, _args) do + ScoutApm.Instruments.FinchTelemetry.attach() + # ... rest of supervision tree + end + + This will automatically instrument all Finch HTTP requests in your application, + including those made through libraries built on Finch (like Req). + + ## What's Tracked + + - **Operation**: `HTTP/{method}` (e.g., "HTTP/GET", "HTTP/POST") + - **URL**: The full URL of the request (sanitized) + - **Status Code**: The HTTP response status code + + ## Configuration + + Requests to Scout APM's own endpoints are automatically excluded from tracking. + """ + + alias ScoutApm.TrackedRequest + alias ScoutApm.Internal.Duration + + require Logger + + @events [ + [:finch, :request, :stop], + [:finch, :request, :exception] + ] + + # Scout APM hosts that should not be instrumented + @scout_hosts [ + "errors.scoutapm.com", + "apm.scoutapp.com", + "checkin.scoutapm.com", + "otlp.scoutotel.com" + ] + + @doc """ + Attaches telemetry handlers for Finch HTTP request events. + + Call this once during application startup. + """ + def attach do + :telemetry.attach_many( + "scout-apm-finch-telemetry", + @events, + &__MODULE__.handle_event/4, + nil + ) + end + + @doc """ + Detaches the telemetry handlers. Useful for testing. + """ + def detach do + :telemetry.detach("scout-apm-finch-telemetry") + end + + # Request completed successfully + def handle_event( + [:finch, :request, :stop], + %{duration: duration} = _measurements, + %{request: request, result: result} = _metadata, + _config + ) do + url = build_url(request) + + if should_instrument?(url) do + method = normalize_method(request) + status_code = extract_status_code(result) + + duration_struct = + Duration.new(System.convert_time_unit(duration, :native, :microsecond), :microseconds) + + TrackedRequest.track_layer( + "HTTP", + method, + duration_struct, + http_method: method, + http_url: url, + http_status_code: status_code + ) + end + + :ok + end + + # Request failed with exception + def handle_event( + [:finch, :request, :exception], + %{duration: duration} = _measurements, + %{request: request, kind: _kind, reason: _reason} = _metadata, + _config + ) do + url = build_url(request) + + if should_instrument?(url) do + method = normalize_method(request) + + duration_struct = + Duration.new(System.convert_time_unit(duration, :native, :microsecond), :microseconds) + + TrackedRequest.track_layer( + "HTTP", + method, + duration_struct, + http_method: method, + http_url: url, + http_status_code: nil + ) + end + + :ok + end + + # Catch-all for unhandled events + def handle_event(_event, _measurements, _metadata, _config), do: :ok + + # Build URL from Finch request struct + defp build_url(%{scheme: scheme, host: host, port: port, path: path}) do + port_str = format_port(scheme, port) + path_str = path || "/" + "#{scheme}://#{host}#{port_str}#{path_str}" + end + + defp build_url(_request), do: "Unknown" + + # Format port, omitting default ports + defp format_port(:https, 443), do: "" + defp format_port(:http, 80), do: "" + defp format_port("https", 443), do: "" + defp format_port("http", 80), do: "" + defp format_port(_scheme, port), do: ":#{port}" + + # Normalize HTTP method to uppercase string + defp normalize_method(%{method: method}) when is_binary(method), do: String.upcase(method) + + defp normalize_method(%{method: method}) when is_atom(method), + do: method |> Atom.to_string() |> String.upcase() + + defp normalize_method(_), do: "UNKNOWN" + + # Extract status code from result + defp extract_status_code({:ok, %{status: status}}), do: status + defp extract_status_code(_), do: nil + + # Check if this URL should be instrumented (exclude Scout APM hosts) + defp should_instrument?(url) when is_binary(url) do + not Enum.any?(@scout_hosts, fn host -> String.contains?(url, host) end) + end + + defp should_instrument?(_), do: true + end +end diff --git a/lib/scout_apm/instruments/heex_engine.ex b/lib/scout_apm/instruments/heex_engine.ex new file mode 100644 index 0000000..e002d97 --- /dev/null +++ b/lib/scout_apm/instruments/heex_engine.ex @@ -0,0 +1,86 @@ +if Code.ensure_loaded?(Phoenix.LiveView.HTMLEngine) do + defmodule ScoutApm.Instruments.HEExEngine do + @moduledoc """ + Scout APM instrumentation for Phoenix HEEx templates (.heex files). + + This engine wraps `Phoenix.LiveView.HTMLEngine` to provide automatic timing + instrumentation for HEEx template rendering. + + ## Requirements + + - Phoenix LiveView 0.17+ + - Phoenix 1.6+ + + ## Configuration + + Add to your `config/config.exs`: + + config :phoenix, :template_engines, + heex: ScoutApm.Instruments.HEExEngine + + The engine will automatically instrument all `.heex` template files in your application. + + ## Notes + + - This module is only compiled when `Phoenix.LiveView.HTMLEngine` is available + - Layout templates are marked as non-scopable to prevent them from becoming transaction names + - Compatible with both Phoenix 1.6 (web/templates) and 1.7+ (lib/my_app_web/controllers) directory structures + """ + + @behaviour Phoenix.Template.Engine + + # TODO: Make this name correctly for other template locations + # Currently it assumes too much about being located under `lib/{app}_web/templates` + def compile(path, name) do + # lib/my_app_web/templates/page/index.html.heex + # OR lib/my_app_web/controllers/page_html/index.html.heex (Phoenix 1.7+) + scout_name = + path + # Split on forward slashes + |> String.split("/") + # Drop the first parts until we get to meaningful template path + # This handles both old-style (web/templates) and new-style (controllers) paths + |> drop_path_prefix() + # "page/index.html.heex" or "page_html/index.html.heex" + |> Enum.join("/") + + # Since we only have a single layer of nesting currently, and + # practically every template will be "under" a layout, don't let the + # layout become the scope. Once we have deeper nesting, we'll want + # to allow layouts as scopable layers. + is_layout = String.contains?(scout_name, "layout") + + quoted_template = Phoenix.LiveView.HTMLEngine.compile(path, name) + + quote do + require ScoutApm.Tracing + + ScoutApm.Tracing.timing("HEEx", unquote(path), [scopable: !unquote(is_layout)], + do: unquote(quoted_template) + ) + end + end + + # Drop path components until we reach the meaningful template path + # Handles: web/templates/*, lib/my_app_web/templates/*, lib/my_app_web/controllers/* + defp drop_path_prefix(path_parts) do + cond do + # Old style: web/templates/page/index.html.heex + Enum.member?(path_parts, "templates") -> + path_parts + |> Enum.drop_while(&(&1 != "templates")) + |> Enum.drop(1) + + # New style: lib/my_app_web/controllers/page_html/index.html.heex + Enum.member?(path_parts, "controllers") -> + path_parts + |> Enum.drop_while(&(&1 != "controllers")) + |> Enum.drop(1) + + # Fallback: just drop first 2 parts (maintains backward compatibility) + true -> + Enum.drop(path_parts, 2) + end + end + end +end diff --git a/lib/scout_apm/instruments/live_view_telemetry.ex b/lib/scout_apm/instruments/live_view_telemetry.ex new file mode 100644 index 0000000..b54f79a --- /dev/null +++ b/lib/scout_apm/instruments/live_view_telemetry.ex @@ -0,0 +1,312 @@ +if Code.ensure_loaded?(Telemetry) || Code.ensure_loaded?(:telemetry) do + defmodule ScoutApm.Instruments.LiveViewTelemetry do + @moduledoc """ + Telemetry handler for Phoenix LiveView instrumentation. + + Attaches to LiveView telemetry events to track: + - LiveView mounts (as "LiveView" type transactions) + - handle_event callbacks (as timed layers within transactions) + - handle_params callbacks (as timed layers within transactions) + + ## Usage + + In your application's `start/2` function: + + def start(_type, _args) do + ScoutApm.Instruments.LiveViewTelemetry.attach() + # ... rest of supervision tree + end + + This will automatically instrument all LiveView modules in your application. + """ + + alias ScoutApm.TrackedRequest + alias ScoutApm.Internal.Layer + + require Logger + + @events [ + [:phoenix, :live_view, :mount, :start], + [:phoenix, :live_view, :mount, :stop], + [:phoenix, :live_view, :mount, :exception], + [:phoenix, :live_view, :handle_event, :start], + [:phoenix, :live_view, :handle_event, :stop], + [:phoenix, :live_view, :handle_event, :exception], + [:phoenix, :live_view, :handle_params, :start], + [:phoenix, :live_view, :handle_params, :stop], + [:phoenix, :live_view, :handle_params, :exception] + ] + + @doc """ + Attaches telemetry handlers for LiveView events. + + Call this once during application startup. + """ + def attach do + Logger.info("[ScoutApm.LiveViewTelemetry] Attaching to events: #{inspect(@events)}") + + result = + :telemetry.attach_many( + "scout-apm-live-view-telemetry", + @events, + &__MODULE__.handle_event/4, + nil + ) + + Logger.info("[ScoutApm.LiveViewTelemetry] Attach result: #{inspect(result)}") + result + end + + @doc """ + Detaches the telemetry handlers. Useful for testing. + """ + def detach do + :telemetry.detach("scout-apm-live-view-telemetry") + end + + # Mount start - begins a new transaction + def handle_event( + [:phoenix, :live_view, :mount, :start], + _measurements, + %{socket: socket} = _metadata, + _config + ) do + view_module = socket.view + name = live_view_name(view_module, "mount") + + # Check existing state before starting + existing = Process.get(:scout_apm_request) + + Logger.info("scout_liveview mount:start", + scout_event: "mount:start", + view: inspect(view_module), + name: name, + existing_request: existing != nil + ) + + # Use "Controller" type so Scout APM backend recognizes it as a web transaction + result = TrackedRequest.start_layer("Controller", name) + ScoutApm.Logging.ContextExtractor.stash_context("Controller", name) + after_start = Process.get(:scout_apm_request) + + Logger.info("scout_liveview mount:start complete", + scout_event: "mount:start:after", + layers: after_start && length(after_start.layers), + success: result != nil + ) + + result + end + + # Mount stop - completes the transaction + def handle_event( + [:phoenix, :live_view, :mount, :stop], + measurements, + %{socket: socket} = _metadata, + _config + ) do + view_module = socket.view + name = live_view_name(view_module, "mount") + uri = get_uri_from_socket(socket) + + before_stop = Process.get(:scout_apm_request) + + Logger.info("scout_liveview mount:stop", + scout_event: "mount:stop:before", + view: inspect(view_module), + name: name, + uri: uri, + duration_ns: measurements[:duration], + layers: before_stop && length(before_stop.layers) + ) + + result = + TrackedRequest.stop_layer(fn layer -> + layer + |> Layer.update_name(name) + |> maybe_update_uri(uri) + end) + + after_stop = Process.get(:scout_apm_request) + + Logger.info("scout_liveview mount:stop complete", + scout_event: "mount:stop:after", + request_cleared: after_stop == nil, + result: inspect(result) + ) + + result + end + + # Mount exception - marks error and completes + def handle_event( + [:phoenix, :live_view, :mount, :exception], + _measurements, + %{socket: socket, kind: kind, reason: reason, stacktrace: stacktrace} = _metadata, + _config + ) do + view_module = socket.view + name = live_view_name(view_module, "mount") + + TrackedRequest.mark_error() + + # Capture full error details + ScoutApm.Error.capture_from_telemetry(kind, reason, stacktrace, + request_path: get_uri_from_socket(socket), + custom_controller: name + ) + + TrackedRequest.stop_layer(fn layer -> + layer + |> Layer.update_name(name) + end) + end + + # Handle event start - begins a new transaction for each user interaction + def handle_event( + [:phoenix, :live_view, :handle_event, :start], + _measurements, + %{socket: socket, event: event} = _metadata, + _config + ) do + view_module = socket.view + name = live_view_name(view_module, "handle_event:#{event}") + + Logger.info( + "[ScoutApm.LiveViewTelemetry] handle_event:start - view=#{inspect(view_module)} event=#{event} name=#{name}" + ) + + # Use "Controller" type so Scout APM backend recognizes it as a web transaction + TrackedRequest.start_layer("Controller", name) + ScoutApm.Logging.ContextExtractor.stash_context("Controller", name) + end + + # Handle event stop + def handle_event( + [:phoenix, :live_view, :handle_event, :stop], + measurements, + %{socket: socket, event: event} = _metadata, + _config + ) do + view_module = socket.view + name = live_view_name(view_module, "handle_event:#{event}") + uri = get_uri_from_socket(socket) + + Logger.info( + "[ScoutApm.LiveViewTelemetry] handle_event:stop - view=#{inspect(view_module)} event=#{event} name=#{name} duration=#{inspect(measurements[:duration])}" + ) + + TrackedRequest.stop_layer(fn layer -> + layer + |> Layer.update_name(name) + |> maybe_update_uri(uri) + end) + end + + # Handle event exception + def handle_event( + [:phoenix, :live_view, :handle_event, :exception], + _measurements, + %{socket: socket, event: event, kind: kind, reason: reason, stacktrace: stacktrace} = + _metadata, + _config + ) do + view_module = socket.view + name = live_view_name(view_module, "handle_event:#{event}") + + TrackedRequest.mark_error() + + # Capture full error details + ScoutApm.Error.capture_from_telemetry(kind, reason, stacktrace, + request_path: get_uri_from_socket(socket), + custom_controller: name + ) + + TrackedRequest.stop_layer(fn layer -> + layer + |> Layer.update_name(name) + end) + end + + # Handle params start + def handle_event( + [:phoenix, :live_view, :handle_params, :start], + _measurements, + %{socket: socket} = _metadata, + _config + ) do + view_module = socket.view + name = live_view_name(view_module, "handle_params") + + # Use "Controller" type so Scout APM backend recognizes it as a web transaction + TrackedRequest.start_layer("Controller", name) + ScoutApm.Logging.ContextExtractor.stash_context("Controller", name) + end + + # Handle params stop + def handle_event( + [:phoenix, :live_view, :handle_params, :stop], + _measurements, + %{socket: socket, uri: uri} = _metadata, + _config + ) do + view_module = socket.view + name = live_view_name(view_module, "handle_params") + + TrackedRequest.stop_layer(fn layer -> + layer + |> Layer.update_name(name) + |> Layer.update_uri(uri) + end) + end + + # Handle params exception + def handle_event( + [:phoenix, :live_view, :handle_params, :exception], + _measurements, + %{socket: socket, kind: kind, reason: reason, stacktrace: stacktrace} = _metadata, + _config + ) do + view_module = socket.view + name = live_view_name(view_module, "handle_params") + + TrackedRequest.mark_error() + + # Capture full error details + ScoutApm.Error.capture_from_telemetry(kind, reason, stacktrace, + request_path: get_uri_from_socket(socket), + custom_controller: name + ) + + TrackedRequest.stop_layer(fn layer -> + layer + |> Layer.update_name(name) + end) + end + + # Catch-all for unhandled events + def handle_event(_event, _measurements, _metadata, _config), do: :ok + + # Helper to format LiveView module name + defp live_view_name(nil, action), do: "Unknown##{action}" + + defp live_view_name(view_module, action) do + view_module + |> Module.split() + # Drop the app name prefix (e.g., "GaggleWeb") + |> Enum.drop(1) + |> Enum.join(".") + |> Kernel.<>("##{action}") + end + + defp get_uri_from_socket(socket) do + case socket do + %{host_uri: %URI{path: path}} when is_binary(path) -> path + _ -> nil + end + end + + defp maybe_update_uri(layer, nil), do: layer + defp maybe_update_uri(layer, uri), do: Layer.update_uri(layer, uri) + end +end diff --git a/lib/scout_apm/instruments/oban_telemetry.ex b/lib/scout_apm/instruments/oban_telemetry.ex new file mode 100644 index 0000000..ae66e2b --- /dev/null +++ b/lib/scout_apm/instruments/oban_telemetry.ex @@ -0,0 +1,151 @@ +if Code.ensure_loaded?(Telemetry) || Code.ensure_loaded?(:telemetry) do + defmodule ScoutApm.Instruments.ObanTelemetry do + @moduledoc """ + Telemetry handler for Oban job instrumentation. + + Attaches to Oban telemetry events to track background jobs: + - Job executions appear as "Job" type background transactions + - Job names are derived from the worker module + + ## Usage + + In your application's `start/2` function: + + def start(_type, _args) do + ScoutApm.Instruments.ObanTelemetry.attach() + # ... rest of supervision tree + end + + This will automatically instrument all Oban job executions in your application. + + ## Transaction Naming + + Jobs are named based on the worker module. For example: + - `MyApp.Workers.SendEmail` becomes `Job/SendEmail` + - `MyApp.EmailWorker` becomes `Job/EmailWorker` + """ + + alias ScoutApm.TrackedRequest + alias ScoutApm.Internal.Layer + + require Logger + + @events [ + [:oban, :job, :start], + [:oban, :job, :stop], + [:oban, :job, :exception] + ] + + @doc """ + Attaches telemetry handlers for Oban job events. + + Call this once during application startup. + """ + def attach do + :telemetry.attach_many( + "scout-apm-oban-telemetry", + @events, + &__MODULE__.handle_event/4, + nil + ) + end + + @doc """ + Detaches the telemetry handlers. Useful for testing. + """ + def detach do + :telemetry.detach("scout-apm-oban-telemetry") + end + + # Job start - begins a new background transaction + def handle_event( + [:oban, :job, :start], + _measurements, + %{job: job} = _metadata, + _config + ) do + name = job_name(job) + + # "Job" is the internal layer type for background transactions + TrackedRequest.start_layer("Job", name) + ScoutApm.Logging.ContextExtractor.stash_context("Job", name) + end + + # Job stop - completes the transaction + def handle_event( + [:oban, :job, :stop], + _measurements, + %{job: job, state: state} = _metadata, + _config + ) do + name = job_name(job) + + # Mark as error if job failed, was cancelled, or discarded + if state in [:failure, :cancelled, :discard] do + TrackedRequest.mark_error() + end + + TrackedRequest.stop_layer(fn layer -> + layer + |> Layer.update_name(name) + |> Layer.update_desc("Queue: #{job.queue}, State: #{state}") + end) + end + + # Job exception - marks error and completes + def handle_event( + [:oban, :job, :exception], + _measurements, + %{job: job, kind: kind, reason: reason, stacktrace: stacktrace} = _metadata, + _config + ) do + name = job_name(job) + + TrackedRequest.mark_error() + + # Capture full error details + ScoutApm.Error.capture_from_telemetry(kind, reason, stacktrace, + custom_controller: name, + custom_params: %{queue: job.queue, worker: job.worker} + ) + + TrackedRequest.stop_layer(fn layer -> + layer + |> Layer.update_name(name) + |> Layer.update_desc("#{kind}: #{format_reason(reason)}") + end) + end + + # Catch-all for unhandled events + def handle_event(_event, _measurements, _metadata, _config), do: :ok + + # Format job name from Oban.Job struct + defp job_name(%{worker: worker}) when is_binary(worker) do + short_name = + worker + |> String.split(".") + |> List.last() + + "Job/#{short_name}" + end + + defp job_name(%{worker: worker}) when is_atom(worker) do + short_name = + worker + |> Module.split() + |> List.last() + + "Job/#{short_name}" + end + + defp job_name(_job), do: "Job/Unknown" + + defp format_reason(reason) when is_exception(reason) do + Exception.message(reason) + end + + defp format_reason(reason) do + inspect(reason, limit: 100) + end + end +end diff --git a/lib/scout_apm/instruments/phoenix_error_telemetry.ex b/lib/scout_apm/instruments/phoenix_error_telemetry.ex new file mode 100644 index 0000000..1956b50 --- /dev/null +++ b/lib/scout_apm/instruments/phoenix_error_telemetry.ex @@ -0,0 +1,141 @@ +if Code.ensure_loaded?(Telemetry) || Code.ensure_loaded?(:telemetry) do + defmodule ScoutApm.Instruments.PhoenixErrorTelemetry do + @moduledoc """ + Telemetry handler for automatic Phoenix error capture. + + Attaches to Phoenix telemetry events to automatically capture: + - Router dispatch exceptions + - Error rendering events + + ## Usage + + In your application's `start/2` function: + + def start(_type, _args) do + ScoutApm.Instruments.PhoenixErrorTelemetry.attach() + # ... rest of supervision tree + end + + This will automatically capture all unhandled exceptions in Phoenix routes. + """ + + @events [ + [:phoenix, :router_dispatch, :exception], + [:phoenix, :error_rendered] + ] + + @doc """ + Attaches telemetry handlers for Phoenix error events. + Call this once during application startup. + """ + def attach do + :telemetry.attach_many( + "scout-apm-phoenix-error-telemetry", + @events, + &__MODULE__.handle_event/4, + nil + ) + end + + @doc """ + Detaches the telemetry handlers. Useful for testing. + """ + def detach do + :telemetry.detach("scout-apm-phoenix-error-telemetry") + end + + # Router dispatch exception - captures full exception info + def handle_event( + [:phoenix, :router_dispatch, :exception], + _measurements, + %{conn: conn, kind: kind, reason: reason, stacktrace: stacktrace} = _metadata, + _config + ) do + # Also mark the tracked request as having an error + ScoutApm.TrackedRequest.mark_error() + + # Extract request information from conn + opts = [ + request_path: conn.request_path, + request_params: extract_params(conn), + session: extract_session(conn), + custom_controller: extract_controller(conn) + ] + + ScoutApm.Error.capture_from_telemetry(kind, reason, stacktrace, opts) + end + + # Error rendered - captures when Phoenix renders an error response + # This is useful for catching errors that bubble up to the error view + def handle_event( + [:phoenix, :error_rendered], + _measurements, + %{status: status, kind: kind, reason: reason, stacktrace: stacktrace} = metadata, + _config + ) + when status >= 500 do + conn = Map.get(metadata, :conn) + + opts = + if conn do + [ + request_path: conn.request_path, + request_params: extract_params(conn), + session: extract_session(conn), + custom_controller: extract_controller(conn) + ] + else + [] + end + + ScoutApm.Error.capture_from_telemetry(kind, reason, stacktrace, opts) + end + + def handle_event([:phoenix, :error_rendered], _measurements, _metadata, _config) do + # Ignore non-500 errors (4xx client errors) + :ok + end + + # Catch-all for unhandled events + def handle_event(_event, _measurements, _metadata, _config), do: :ok + + # Private helpers + + defp extract_params(conn) do + try do + conn.params + rescue + _ -> nil + end + end + + defp extract_session(conn) do + try do + Plug.Conn.get_session(conn) + rescue + _ -> nil + end + end + + defp extract_controller(conn) do + controller = conn.private[:phoenix_controller] + action = conn.private[:phoenix_action] + + if controller do + controller_name = + controller + |> Module.split() + |> Enum.drop(1) + |> Enum.join(".") + + if action do + "#{controller_name}##{action}" + else + controller_name + end + else + nil + end + end + end +end diff --git a/lib/scout_apm/instruments/tesla_telemetry.ex b/lib/scout_apm/instruments/tesla_telemetry.ex new file mode 100644 index 0000000..48c653a --- /dev/null +++ b/lib/scout_apm/instruments/tesla_telemetry.ex @@ -0,0 +1,213 @@ +if Code.ensure_loaded?(Telemetry) || Code.ensure_loaded?(:telemetry) do + defmodule ScoutApm.Instruments.TeslaTelemetry do + @moduledoc """ + Telemetry handler for Tesla HTTP client instrumentation. + + Attaches to Tesla telemetry events to track external HTTP requests: + - HTTP requests appear as "HTTP" type layers (External Services) + - Tracks URL, HTTP method, and response status code + + ## Prerequisites + + Your Tesla client must include the Telemetry middleware. Add it to your client: + + defmodule MyApp.ApiClient do + use Tesla + + plug Tesla.Middleware.Telemetry + plug Tesla.Middleware.BaseUrl, "https://api.example.com" + # ... other middleware + end + + **Important:** Place `Tesla.Middleware.Telemetry` as close as possible to the end + of the middleware stack to ensure accurate timing measurements. + + ## Usage + + In your application's `start/2` function: + + def start(_type, _args) do + ScoutApm.Instruments.TeslaTelemetry.attach() + # ... rest of supervision tree + end + + ## What's Tracked + + - **Operation**: `HTTP/{method}` (e.g., "HTTP/GET", "HTTP/POST") + - **URL**: The full URL of the request (sanitized) + - **Status Code**: The HTTP response status code + + ## Configuration + + Requests to Scout APM's own endpoints are automatically excluded from tracking. + """ + + alias ScoutApm.TrackedRequest + alias ScoutApm.Internal.Duration + + require Logger + + @events [ + [:tesla, :request, :stop], + [:tesla, :request, :exception] + ] + + # Scout APM hosts that should not be instrumented + @scout_hosts [ + "errors.scoutapm.com", + "apm.scoutapp.com", + "checkin.scoutapm.com", + "otlp.scoutotel.com" + ] + + @doc """ + Attaches telemetry handlers for Tesla HTTP request events. + + Call this once during application startup. + """ + def attach do + :telemetry.attach_many( + "scout-apm-tesla-telemetry", + @events, + &__MODULE__.handle_event/4, + nil + ) + end + + @doc """ + Detaches the telemetry handlers. Useful for testing. + """ + def detach do + :telemetry.detach("scout-apm-tesla-telemetry") + end + + # Request completed with error in metadata — must come before success clause + # since %{env: env} would also match maps containing an :error key + def handle_event( + [:tesla, :request, :stop], + %{duration: duration} = _measurements, + %{env: env, error: _error} = _metadata, + _config + ) do + url = build_url(env) + + if should_instrument?(url) do + method = normalize_method(env) + + duration_struct = + Duration.new(System.convert_time_unit(duration, :native, :microsecond), :microseconds) + + TrackedRequest.track_layer( + "HTTP", + method, + duration_struct, + http_method: method, + http_url: url, + http_status_code: nil + ) + end + + :ok + end + + # Request completed successfully + def handle_event( + [:tesla, :request, :stop], + %{duration: duration} = _measurements, + %{env: env} = _metadata, + _config + ) do + url = build_url(env) + + if should_instrument?(url) do + method = normalize_method(env) + status_code = extract_status_code(env) + + duration_struct = + Duration.new(System.convert_time_unit(duration, :native, :microsecond), :microseconds) + + TrackedRequest.track_layer( + "HTTP", + method, + duration_struct, + http_method: method, + http_url: url, + http_status_code: status_code + ) + end + + :ok + end + + # Request failed with exception + def handle_event( + [:tesla, :request, :exception], + %{duration: duration} = _measurements, + %{env: env} = _metadata, + _config + ) do + url = build_url(env) + + if should_instrument?(url) do + method = normalize_method(env) + + duration_struct = + Duration.new(System.convert_time_unit(duration, :native, :microsecond), :microseconds) + + TrackedRequest.track_layer( + "HTTP", + method, + duration_struct, + http_method: method, + http_url: url, + http_status_code: nil + ) + end + + :ok + end + + # Catch-all for unhandled events + def handle_event(_event, _measurements, _metadata, _config), do: :ok + + # Build URL from Tesla.Env struct, stripping query strings to avoid leaking sensitive data + defp build_url(%{url: url}) when is_binary(url) do + case URI.parse(url) do + %URI{scheme: scheme, host: host, port: port, path: path} + when is_binary(scheme) and is_binary(host) -> + port_str = format_port(scheme, port) + path_str = path || "/" + "#{scheme}://#{host}#{port_str}#{path_str}" + + _ -> + url + end + end + + defp build_url(_env), do: "Unknown" + + # Format port, omitting default ports + defp format_port("https", 443), do: "" + defp format_port("http", 80), do: "" + defp format_port(_, nil), do: "" + defp format_port(_, port), do: ":#{port}" + + # Normalize HTTP method to uppercase string + defp normalize_method(%{method: method}) when is_atom(method), + do: method |> Atom.to_string() |> String.upcase() + + defp normalize_method(%{method: method}) when is_binary(method), do: String.upcase(method) + defp normalize_method(_), do: "UNKNOWN" + + # Extract status code from Tesla.Env + defp extract_status_code(%{status: status}) when is_integer(status), do: status + defp extract_status_code(_), do: nil + + # Check if this URL should be instrumented (exclude Scout APM hosts) + defp should_instrument?(url) when is_binary(url) do + not Enum.any?(@scout_hosts, fn host -> String.contains?(url, host) end) + end + + defp should_instrument?(_), do: true + end +end diff --git a/lib/scout_apm/internal/layer.ex b/lib/scout_apm/internal/layer.ex index 573d873..1e8305e 100644 --- a/lib/scout_apm/internal/layer.ex +++ b/lib/scout_apm/internal/layer.ex @@ -15,7 +15,12 @@ defmodule ScoutApm.Internal.Layer do stopped_at: nil | Integer, scopable: boolean, manual_duration: nil | ScoutApm.Internal.Duration.t(), - children: list(%__MODULE__{}) + children: list(%__MODULE__{}), + db_command: nil | String.t(), + db_rows: nil | non_neg_integer(), + http_method: nil | String.t(), + http_url: nil | String.t(), + http_status_code: nil | non_neg_integer() } defstruct [ @@ -30,6 +35,15 @@ defmodule ScoutApm.Internal.Layer do # If this is set, ignore started_at -> stopped_at valuse when calculating # how long this layer ran :manual_duration, + + # Database-specific fields for Ecto layers + :db_command, + :db_rows, + + # HTTP-specific fields for External Service layers + :http_method, + :http_url, + :http_status_code, scopable: true, children: [] ] @@ -88,6 +102,26 @@ defmodule ScoutApm.Internal.Layer do %{layer | manual_duration: duration} end + def update_db_command(layer, db_command) do + %{layer | db_command: db_command} + end + + def update_db_rows(layer, db_rows) do + %{layer | db_rows: db_rows} + end + + def update_http_method(layer, http_method) do + %{layer | http_method: http_method} + end + + def update_http_url(layer, http_url) do + %{layer | http_url: http_url} + end + + def update_http_status_code(layer, http_status_code) do + %{layer | http_status_code: http_status_code} + end + ################## # Update Fields # ################## @@ -103,6 +137,11 @@ defmodule ScoutApm.Internal.Layer do defp update_field(layer, :desc, value), do: update_desc(layer, value) defp update_field(layer, :backtrace, value), do: update_backtrace(layer, value) + defp update_field(layer, :db_command, value), do: update_db_command(layer, value) + defp update_field(layer, :db_rows, value), do: update_db_rows(layer, value) + defp update_field(layer, :http_method, value), do: update_http_method(layer, value) + defp update_field(layer, :http_url, value), do: update_http_url(layer, value) + defp update_field(layer, :http_status_code, value), do: update_http_status_code(layer, value) ############# # Queries # diff --git a/lib/scout_apm/logger.ex b/lib/scout_apm/logger.ex index adb82b0..830799b 100644 --- a/lib/scout_apm/logger.ex +++ b/lib/scout_apm/logger.ex @@ -13,13 +13,14 @@ defmodule ScoutApm.Logger do @default_level :info - @valid_levels [:debug, :info, :warn, :error] + # Support both :warn (deprecated) and :warning for backwards compatibility + @valid_levels [:debug, :info, :warn, :warning, :error] # If you request to log a message at the left level, check if the # logger's current level is one of the right before letting it through # - # For instance, if you ScoutApm.Logger.log(:warn, "foo"), it should be - # printed if you're at warn, info, or debug levels + # For instance, if you ScoutApm.Logger.log(:warning, "foo"), it should be + # printed if you're at warning, info, or debug levels # # Msg Lvl Logger Lvl # | | @@ -27,13 +28,14 @@ defmodule ScoutApm.Logger do # v v @debug_levels [:debug] @info_levels [:debug, :info] - @warn_levels [:debug, :info, :warn] - @error_levels [:debug, :info, :warn, :error] + @warn_levels [:debug, :info, :warn, :warning] + @error_levels [:debug, :info, :warn, :warning, :error] @log_levels %{ debug: @debug_levels, info: @info_levels, warn: @warn_levels, + warning: @warn_levels, error: @error_levels } @@ -42,7 +44,9 @@ defmodule ScoutApm.Logger do with {:ok, levels} <- logging_enabled() && Map.fetch(@log_levels, level), true <- log_level in levels do - Logger.log(level, chardata_or_fun, metadata) + # Convert :warn to :warning for Elixir 1.15+ compatibility + erlang_level = if level == :warn, do: :warning, else: level + Logger.log(erlang_level, chardata_or_fun, metadata) else _ -> :ok end diff --git a/lib/scout_apm/logging.ex b/lib/scout_apm/logging.ex new file mode 100644 index 0000000..b0dae3e --- /dev/null +++ b/lib/scout_apm/logging.ex @@ -0,0 +1,140 @@ +defmodule ScoutApm.Logging do + @moduledoc """ + Public API for Scout APM's OTLP logging integration. + + This module provides functions to capture Elixir Logger messages, + enrich them with Scout APM context (request ID, transaction name, custom tags), + and send them to an OpenTelemetry collector via OTLP. + + ## Setup + + 1. Add configuration to your `config/config.exs`: + + config :scout_apm, + logs_enabled: true, + logs_ingest_key: "your-logs-key" + + 2. Attach the log handler in your application startup: + + def start(_type, _args) do + ScoutApm.Logging.attach() + # ... rest of supervision tree + end + + ## Configuration Options + + - `:logs_enabled` - Enable/disable log capture (default: `false`) + - `:logs_endpoint` - OTLP collector URL (default: `"https://otlp.scoutotel.com:4318"`) + - `:logs_ingest_key` - Authentication key (falls back to `:key`) + - `:logs_level` - Minimum log level to capture (default: `:info`) + - `:logs_batch_size` - Logs per batch (default: `100`) + - `:logs_max_queue_size` - Maximum queued logs (default: `5000`) + - `:logs_flush_interval_ms` - Flush interval in ms (default: `5000`) + - `:logs_filter_modules` - List of modules to exclude from capture + + ## Context Enrichment + + Logs captured within Scout-tracked requests are automatically enriched with: + + - `scout.request_id` - Unique request identifier + - `scout.transaction_name` - e.g., "Controller/UserController#show" + - `scout.layer_type` - Current operation type + - `scout.layer_name` - Current operation name + - `scout.tag.{key}` - Custom tags from `ScoutApm.Context.add/2` + - `scout.user.{key}` - User context from `ScoutApm.Context.add_user/2` + - `service.name` - Application name from config + + ## Example + + # Logs are automatically enriched when inside a Scout-tracked request + def show(conn, %{"id" => id}) do + user = Repo.get!(User, id) + Logger.info("Fetched user", user_id: id) # Will include Scout context + render(conn, :show, user: user) + end + + # Add custom context that appears in logs + ScoutApm.Context.add("feature_flag", "new_checkout") + Logger.info("Processing checkout") # Includes scout.tag.feature_flag + """ + + alias ScoutApm.Logging.{LogHandler, LogService} + + @doc """ + Attaches the Scout APM log handler to capture Logger messages. + + ## Options + + - `:level` - Minimum log level to capture (default: from config or `:info`) + - `:filter_modules` - Additional modules to exclude from capture + + ## Examples + + # Basic attach + ScoutApm.Logging.attach() + + # With options + ScoutApm.Logging.attach(level: :warning, filter_modules: [MyApp.Verbose]) + """ + @spec attach(keyword()) :: :ok | {:error, term()} + def attach(opts \\ []) do + LogHandler.attach(opts) + end + + @doc """ + Detaches the Scout APM log handler. + Logs will no longer be captured and sent to the OTLP collector. + """ + @spec detach() :: :ok | {:error, term()} + def detach do + LogHandler.detach() + end + + @doc """ + Returns true if the log handler is currently attached. + """ + @spec attached?() :: boolean() + def attached? do + LogHandler.attached?() + end + + @doc """ + Returns true if logging is enabled via configuration. + """ + @spec enabled?() :: boolean() + def enabled? do + LogService.enabled?() + end + + @doc """ + Forces an immediate flush of queued log records. + Useful for testing or before application shutdown. + """ + @spec flush() :: :ok + def flush do + LogService.flush() + end + + @doc """ + Waits for the log queue to drain (all logs sent). + Used during testing or graceful shutdown. + + ## Options + + - `timeout` - Maximum time to wait in milliseconds (default: 5000) + + Returns `:ok` if queue is empty, `:timeout` if timeout is reached. + """ + @spec drain(timeout :: non_neg_integer()) :: :ok | :timeout + def drain(timeout \\ 5_000) do + LogService.drain(timeout) + end + + @doc """ + Returns the current number of queued log records. + """ + @spec queue_size() :: non_neg_integer() + def queue_size do + LogService.queue_size() + end +end diff --git a/lib/scout_apm/logging/context_extractor.ex b/lib/scout_apm/logging/context_extractor.ex new file mode 100644 index 0000000..1cdf87e --- /dev/null +++ b/lib/scout_apm/logging/context_extractor.ex @@ -0,0 +1,236 @@ +defmodule ScoutApm.Logging.ContextExtractor do + @moduledoc """ + Extracts Scout APM context from the current process for log enrichment. + + Reads from Process.get(:scout_apm_request) to extract: + - scout_transaction_id - TrackedRequest.id + - scout_start_time - Root layer start time (ISO 8601) + - scout_end_time - Root layer end time (ISO 8601, if completed) + - scout_duration - Request duration in seconds (if completed) + - scout_current_operation - Current span's type/name + - controller_entrypoint / job_entrypoint / custom_entrypoint - Entrypoint name + - scout_tag_{key} - Custom tags from ScoutApm.Context + - user.{key} - User context (excluding ip) + - service.name - From config + """ + + require Logger + + alias ScoutApm.TrackedRequest + alias ScoutApm.Internal.Context + + @doc """ + Extracts Scout APM context from the current process. + Returns a list of {key, value} tuples suitable for log enrichment. + """ + @spec extract() :: list({String.t(), any()}) + def extract do + case Process.get(:scout_apm_request) do + %TrackedRequest{} = tr -> + extract_from_tracked_request(tr) + + _ -> + base_context() ++ extract_from_logger_metadata() + end + end + + @doc """ + Extracts context from a specific TrackedRequest struct. + """ + @spec extract_from_tracked_request(TrackedRequest.t()) :: list({String.t(), any()}) + def extract_from_tracked_request(%TrackedRequest{} = tr) do + base = base_context() + + request_context = [ + {"scout_transaction_id", tr.id} + ] + + timing_context = extract_timing_context(tr) + layer_context = extract_layer_context(tr) + custom_context = extract_custom_context(tr.contexts) + + (base ++ request_context ++ timing_context ++ layer_context ++ custom_context) + |> Enum.filter(fn {_k, v} -> v != nil end) + end + + @doc """ + Stashes Scout context into Logger metadata so it survives TrackedRequest cleanup. + + Call this when a Controller or Job layer starts. The metadata persists on the + process for the entire request lifetime, so logs emitted after TrackedRequest + is cleaned up (e.g., Phoenix endpoint stop logs) still get Scout context. + """ + @spec stash_context(String.t(), String.t()) :: :ok + def stash_context(type, name) when is_binary(type) and is_binary(name) do + {key, _} = entrypoint_key_value(type, name) + + transaction_id = + case Process.get(:scout_apm_request) do + %TrackedRequest{id: id} -> id + _ -> nil + end + + metadata = + [scout_entrypoint_key: key, scout_entrypoint_name: name] ++ + if(transaction_id, do: [scout_transaction_id: transaction_id], else: []) + + Logger.metadata(metadata) + + :ok + end + + # Private functions + + defp extract_from_logger_metadata do + meta = Logger.metadata() + key = meta[:scout_entrypoint_key] + name = meta[:scout_entrypoint_name] + transaction_id = meta[:scout_transaction_id] + + entrypoint = + if key && name do + [{key, name}] + else + [] + end + + tx_id = + if transaction_id do + [{"scout_transaction_id", transaction_id}] + else + [] + end + + tx_id ++ entrypoint + end + + defp entrypoint_key_value("Controller", name), do: {"controller_entrypoint", name} + defp entrypoint_key_value("Job", name), do: {"job_entrypoint", name} + defp entrypoint_key_value(_type, name), do: {"custom_entrypoint", name} + + defp base_context do + service_name = ScoutApm.Config.find(:name) + + if service_name do + [{"service.name", service_name}] + else + [] + end + end + + defp extract_timing_context(%TrackedRequest{root_layer: nil}), do: [] + + defp extract_timing_context(%TrackedRequest{root_layer: layer}) do + start_attrs = + if layer.started_at do + [{"scout_start_time", NaiveDateTime.to_iso8601(layer.started_at) <> "Z"}] + else + [] + end + + end_attrs = + if layer.stopped_at do + duration = + NaiveDateTime.diff(layer.stopped_at, layer.started_at, :microsecond) / 1_000_000 + + [ + {"scout_end_time", NaiveDateTime.to_iso8601(layer.stopped_at) <> "Z"}, + {"scout_duration", duration} + ] + else + [] + end + + start_attrs ++ end_attrs + end + + defp extract_layer_context(%TrackedRequest{layers: layers, root_layer: root_layer}) + when is_list(layers) do + # Determine the entrypoint layer: prefer Controller/Job from root_layer, + # then search the layers stack (outermost = last element), then fall back + # to root_layer or the outermost active layer. + entrypoint_layer = + cond do + root_layer != nil and root_layer.type in ["Controller", "Job"] -> + root_layer + + # Search layers stack for a Controller/Job (last = outermost) + (found = Enum.find(Enum.reverse(layers), &(&1.type in ["Controller", "Job"]))) != nil -> + found + + root_layer != nil -> + root_layer + + layers != [] -> + List.last(layers) + + true -> + nil + end + + # Current operation from active layer stack + current_op = + case layers do + [current | _] -> + [{"scout_current_operation", "#{current.type}/#{current.name}"}] + + [] -> + [] + end + + entrypoint_attrs = + case entrypoint_layer do + nil -> [] + layer -> entrypoint_attribute(layer) + end + + current_op ++ entrypoint_attrs + end + + defp extract_layer_context(_), do: [] + + defp entrypoint_attribute(%{type: "Controller", name: name}) when is_binary(name) do + [{"controller_entrypoint", name}] + end + + defp entrypoint_attribute(%{type: "Job", name: name}) when is_binary(name) do + [{"job_entrypoint", name}] + end + + defp entrypoint_attribute(%{type: type, name: name}) + when is_binary(type) and is_binary(name) do + [{"custom_entrypoint", name}] + end + + defp entrypoint_attribute(_), do: [] + + defp extract_custom_context(nil), do: [] + defp extract_custom_context([]), do: [] + + defp extract_custom_context(contexts) when is_list(contexts) do + contexts + |> Enum.map(&context_to_attribute/1) + |> Enum.filter(fn {_k, v} -> v != nil end) + end + + defp context_to_attribute(%Context{type: :extra, key: key, value: value}) do + {"scout_tag_#{key}", safe_value(value)} + end + + defp context_to_attribute(%Context{type: :user, key: key, value: _value}) + when key in ["ip", :ip] do + {nil, nil} + end + + defp context_to_attribute(%Context{type: :user, key: key, value: value}) do + {"user.#{key}", safe_value(value)} + end + + defp context_to_attribute(_), do: {nil, nil} + + defp safe_value(value) when is_binary(value), do: value + defp safe_value(value) when is_number(value), do: value + defp safe_value(value) when is_boolean(value), do: value + defp safe_value(value) when is_atom(value), do: Atom.to_string(value) + defp safe_value(value), do: inspect(value, limit: 100) +end diff --git a/lib/scout_apm/logging/log_handler.ex b/lib/scout_apm/logging/log_handler.ex new file mode 100644 index 0000000..541e3ff --- /dev/null +++ b/lib/scout_apm/logging/log_handler.ex @@ -0,0 +1,192 @@ +defmodule ScoutApm.Logging.LogHandler do + @moduledoc """ + Erlang :logger handler for capturing log events and sending them to OTLP. + + This handler runs in the client process (the process that calls Logger), + which allows us to directly access Scout APM context from the process dictionary. + + ## Usage + + # Attach the handler + ScoutApm.Logging.LogHandler.attach() + + # Detach the handler + ScoutApm.Logging.LogHandler.detach() + + ## Configuration + + The handler respects the following config options: + - `:logs_enabled` - Must be true for handler to process logs + - `:logs_level` - Minimum level to capture (default: :info) + - `:logs_filter_modules` - List of modules to exclude from capture + """ + + alias ScoutApm.Logging.{LogRecord, LogService, ContextExtractor} + alias ScoutApm.Logging.OTLP.Severity + + @handler_id :scout_apm_log_handler + @recursion_flag :scout_apm_log_handler_active + + # Scout modules to always filter out (prevent recursion) + @internal_modules [ + ScoutApm.Logging.LogHandler, + ScoutApm.Logging.LogService, + ScoutApm.Logging.OTLP.Exporter, + ScoutApm.Logging.OTLP.Encoder, + ScoutApm.Logger + ] + + @doc """ + Attaches the log handler to the Erlang :logger system. + Returns :ok on success, {:error, reason} on failure. + """ + @spec attach(keyword()) :: :ok | {:error, term()} + def attach(opts \\ []) do + config = %{ + level: Keyword.get(opts, :level, get_default_level()), + filter_modules: Keyword.get(opts, :filter_modules, get_filter_modules()) + } + + case :logger.add_handler(@handler_id, __MODULE__, %{config: config}) do + :ok -> + ScoutApm.Logger.log(:info, "Scout APM log handler attached") + :ok + + {:error, {:already_exist, _}} -> + :ok + + {:error, reason} = error -> + ScoutApm.Logger.log(:debug, "Failed to attach Scout APM log handler: #{inspect(reason)}") + error + end + end + + @doc """ + Detaches the log handler from the Erlang :logger system. + """ + @spec detach() :: :ok | {:error, term()} + def detach do + case :logger.remove_handler(@handler_id) do + :ok -> + ScoutApm.Logger.log(:info, "Scout APM log handler detached") + :ok + + {:error, {:not_found, _}} -> + :ok + + {:error, reason} = error -> + ScoutApm.Logger.log(:debug, "Failed to detach Scout APM log handler: #{inspect(reason)}") + error + end + end + + @doc """ + Checks if the handler is currently attached. + """ + @spec attached?() :: boolean() + def attached? do + @handler_id in :logger.get_handler_ids() + end + + @doc """ + Returns the handler ID used for registration. + """ + @spec handler_id() :: atom() + def handler_id, do: @handler_id + + # Erlang :logger handler callbacks + + @doc false + def adding_handler(config) do + {:ok, config} + end + + @doc false + def removing_handler(_config) do + :ok + end + + @doc false + def changing_config(_action, _old_config, new_config) do + {:ok, new_config} + end + + # Main callback - receives log events in the client process. + # This is where we capture Scout context from the process dictionary. + @doc false + def log(event, config) do + # Prevent recursion - if we're already processing a log, skip + if Process.get(@recursion_flag) do + :ok + else + try do + Process.put(@recursion_flag, true) + do_log(event, config) + after + Process.delete(@recursion_flag) + end + end + end + + # Private functions + + defp do_log(event, config) do + # Check if logging is enabled + unless LogService.enabled?() do + :ok + else + handler_config = get_handler_config(config) + + # Check if this event should be processed + if should_process?(event, handler_config) do + # Extract Scout context from current process + scout_context = ContextExtractor.extract() + + # Create log record + record = LogRecord.from_logger_event(event, scout_context) + + # Send to service for batching + LogService.send(record) + end + + :ok + end + end + + defp get_handler_config(%{config: config}), do: config + defp get_handler_config(_), do: %{} + + defp should_process?(event, config) do + level = Map.get(event, :level, :info) + min_level = Map.get(config, :level, :info) + filter_modules = Map.get(config, :filter_modules, []) + + meets_level?(level, min_level) and + not from_filtered_module?(event, filter_modules) + end + + defp meets_level?(level, min_level) do + Severity.meets_level?(level, min_level) + end + + defp from_filtered_module?(event, user_filter_modules) do + all_filtered = @internal_modules ++ user_filter_modules + + case get_event_module(event) do + nil -> false + module -> module in all_filtered + end + end + + defp get_event_module(%{meta: %{mfa: {module, _fun, _arity}}}), do: module + defp get_event_module(%{meta: %{module: module}}), do: module + defp get_event_module(_), do: nil + + defp get_default_level do + ScoutApm.Config.find(:logs_level) || :info + end + + defp get_filter_modules do + ScoutApm.Config.find(:logs_filter_modules) || [] + end +end diff --git a/lib/scout_apm/logging/log_record.ex b/lib/scout_apm/logging/log_record.ex new file mode 100644 index 0000000..5d88728 --- /dev/null +++ b/lib/scout_apm/logging/log_record.ex @@ -0,0 +1,230 @@ +defmodule ScoutApm.Logging.LogRecord do + @moduledoc """ + Internal struct representing a log record to be sent via OTLP. + + Captures all relevant information from an Elixir Logger event + and Scout APM context for export to an OTLP collector. + """ + + @type t :: %__MODULE__{ + timestamp_nanos: pos_integer(), + observed_timestamp_nanos: pos_integer(), + severity: atom(), + message: String.t(), + attributes: map(), + trace_id: String.t() | nil, + span_id: String.t() | nil, + source_location: map() | nil, + dropped_attributes_count: non_neg_integer() + } + + defstruct [ + :timestamp_nanos, + :observed_timestamp_nanos, + :severity, + :message, + :attributes, + :trace_id, + :span_id, + :source_location, + dropped_attributes_count: 0 + ] + + @max_attributes 128 + @max_message_length 32_768 + + @doc """ + Creates a new LogRecord from an Erlang :logger event. + """ + @spec from_logger_event(map(), keyword()) :: t() + def from_logger_event(event, scout_context \\ []) do + now_nanos = System.system_time(:nanosecond) + + # Extract timestamp from event or use current time + timestamp_nanos = extract_timestamp(event) + + # Extract severity level + severity = Map.get(event, :level, :info) + + # Format the message + message = format_message(event) + + # Build attributes from metadata and Scout context + {attributes, dropped_count} = build_attributes(event, scout_context) + + # Extract source location if available + source_location = extract_source_location(event) + + %__MODULE__{ + timestamp_nanos: timestamp_nanos, + observed_timestamp_nanos: now_nanos, + severity: severity, + message: message, + attributes: attributes, + trace_id: Keyword.get(scout_context, :trace_id), + span_id: Keyword.get(scout_context, :span_id), + source_location: source_location, + dropped_attributes_count: dropped_count + } + end + + @doc """ + Creates a LogRecord from simple parameters (for testing or direct use). + """ + @spec new(atom(), String.t(), map()) :: t() + def new(severity, message, attributes \\ %{}) do + now_nanos = System.system_time(:nanosecond) + {limited_attrs, dropped_count} = limit_attributes(attributes) + + %__MODULE__{ + timestamp_nanos: now_nanos, + observed_timestamp_nanos: now_nanos, + severity: severity, + message: truncate_message(message), + attributes: limited_attrs, + dropped_attributes_count: dropped_count + } + end + + # Private functions + + defp extract_timestamp(%{meta: %{time: time}}) when is_integer(time) do + # Erlang logger time is in microseconds + time * 1000 + end + + defp extract_timestamp(_event) do + System.system_time(:nanosecond) + end + + defp format_message(%{msg: {:string, msg}}) when is_list(msg) do + msg |> IO.iodata_to_binary() |> truncate_message() + end + + defp format_message(%{msg: {:string, msg}}) when is_binary(msg) do + truncate_message(msg) + end + + defp format_message(%{msg: {:report, report}}) do + report |> inspect(limit: 500) |> truncate_message() + end + + defp format_message(%{msg: {format, args}}) when is_list(args) do + try do + :io_lib.format(format, args) |> IO.iodata_to_binary() |> truncate_message() + rescue + _ -> inspect({format, args}) |> truncate_message() + end + end + + defp format_message(_event) do + "" + end + + defp truncate_message(msg) when byte_size(msg) > @max_message_length do + String.slice(msg, 0, @max_message_length - 3) <> "..." + end + + defp truncate_message(msg), do: msg + + defp build_attributes(event, scout_context) do + # Start with metadata from the log event + metadata_attrs = extract_metadata(event) + + # Add Scout context + scout_attrs = + scout_context + |> Keyword.drop([:trace_id, :span_id]) + |> Enum.into(%{}) + + # Add source location as attributes + source_attrs = extract_source_attrs(event) + + # Merge all attributes + all_attrs = + metadata_attrs + |> Map.merge(scout_attrs) + |> Map.merge(source_attrs) + + limit_attributes(all_attrs) + end + + defp extract_metadata(%{meta: meta}) when is_map(meta) do + # Filter out internal logger metadata + internal_keys = [:time, :gl, :pid, :file, :line, :mfa, :domain, :error_logger] + + meta + |> Map.drop(internal_keys) + |> Enum.map(fn {k, v} -> {to_string(k), safe_value(v)} end) + |> Enum.into(%{}) + end + + defp extract_metadata(_), do: %{} + + defp extract_source_attrs(%{meta: %{file: file, line: line, mfa: {mod, fun, arity}}}) do + %{ + "code.filepath" => safe_string(file), + "code.lineno" => line, + "code.function" => "#{inspect(mod)}.#{fun}/#{arity}" + } + end + + defp extract_source_attrs(%{meta: %{file: file, line: line}}) do + %{ + "code.filepath" => safe_string(file), + "code.lineno" => line + } + end + + defp extract_source_attrs(_), do: %{} + + defp extract_source_location(%{meta: %{file: file, line: line, mfa: {mod, fun, arity}}}) do + %{ + "file" => safe_string(file), + "line" => line, + "function" => "#{inspect(mod)}.#{fun}/#{arity}" + } + end + + defp extract_source_location(%{meta: %{file: file, line: line}}) do + %{ + "file" => safe_string(file), + "line" => line + } + end + + defp extract_source_location(_), do: nil + + defp safe_string(value) when is_list(value), do: List.to_string(value) + defp safe_string(value) when is_binary(value), do: value + defp safe_string(value), do: inspect(value) + + defp safe_value(value) when is_binary(value), do: value + defp safe_value(value) when is_number(value), do: value + defp safe_value(value) when is_boolean(value), do: value + defp safe_value(value) when is_atom(value), do: Atom.to_string(value) + defp safe_value(value) when is_list(value), do: Enum.map(value, &safe_value/1) + + defp safe_value(value) when is_map(value) do + value + |> Enum.map(fn {k, v} -> {to_string(k), safe_value(v)} end) + |> Enum.into(%{}) + end + + defp safe_value(value), do: inspect(value, limit: 100) + + defp limit_attributes(attrs) when map_size(attrs) <= @max_attributes do + {attrs, 0} + end + + defp limit_attributes(attrs) do + dropped = map_size(attrs) - @max_attributes + + limited = + attrs + |> Enum.take(@max_attributes) + |> Enum.into(%{}) + + {limited, dropped} + end +end diff --git a/lib/scout_apm/logging/log_service.ex b/lib/scout_apm/logging/log_service.ex new file mode 100644 index 0000000..a475d5e --- /dev/null +++ b/lib/scout_apm/logging/log_service.ex @@ -0,0 +1,219 @@ +defmodule ScoutApm.Logging.LogService do + @moduledoc """ + Background GenServer that batches and sends log records to an OTLP collector. + + Implements a queue with batching and a maximum queue size to prevent memory issues. + Follows the same pattern as ScoutApm.Error.ErrorService. + """ + + use GenServer + + alias ScoutApm.Logging.LogRecord + alias ScoutApm.Logging.OTLP.Exporter + + @default_batch_size 100 + @default_max_queue_size 5000 + @default_flush_interval_ms 5_000 + + defstruct [ + :queue, + :queue_size, + :timer_ref + ] + + @type t :: %__MODULE__{ + queue: :queue.queue(LogRecord.t()), + queue_size: non_neg_integer(), + timer_ref: reference() | nil + } + + # Client API + + def start_link(opts \\ []) do + GenServer.start_link(__MODULE__, opts, name: __MODULE__) + end + + @doc """ + Sends a log record to the service for batched delivery. + Non-blocking - returns immediately. + """ + @spec send(LogRecord.t()) :: :ok + def send(%LogRecord{} = record) do + if enabled?() do + GenServer.cast(__MODULE__, {:send, record}) + else + :ok + end + end + + @doc """ + Waits for the queue to drain. Used in tests and shutdown. + """ + @spec drain(timeout :: non_neg_integer()) :: :ok | :timeout + def drain(timeout \\ 5_000) do + GenServer.call(__MODULE__, :drain, timeout) + catch + :exit, _ -> :timeout + end + + @doc """ + Forces an immediate flush of queued logs. Used in tests. + """ + @spec flush() :: :ok + def flush do + GenServer.call(__MODULE__, :flush) + end + + @doc """ + Returns the current queue size. + """ + @spec queue_size() :: non_neg_integer() + def queue_size do + GenServer.call(__MODULE__, :queue_size) + catch + :exit, _ -> 0 + end + + @doc """ + Checks if logging is enabled. + """ + @spec enabled?() :: boolean() + def enabled? do + ScoutApm.Config.find(:logs_enabled) == true + end + + # Server Callbacks + + @impl GenServer + def init(_opts) do + state = %__MODULE__{ + queue: :queue.new(), + queue_size: 0, + timer_ref: nil + } + + {:ok, schedule_flush(state)} + end + + @impl GenServer + def handle_cast({:send, %LogRecord{} = record}, state) do + max_size = get_max_queue_size() + + if state.queue_size >= max_size do + ScoutApm.Logger.log(:debug, "Log queue full (#{max_size}), dropping log record") + {:noreply, state} + else + new_queue = :queue.in(record, state.queue) + new_state = %{state | queue: new_queue, queue_size: state.queue_size + 1} + + # If we've hit batch size, flush immediately + if new_state.queue_size >= get_batch_size() do + {:noreply, do_flush(new_state)} + else + {:noreply, new_state} + end + end + end + + @impl GenServer + def handle_call(:drain, _from, state) do + new_state = drain_all(state) + {:reply, :ok, new_state} + end + + @impl GenServer + def handle_call(:flush, _from, state) do + new_state = do_flush(state) + {:reply, :ok, new_state} + end + + @impl GenServer + def handle_call(:queue_size, _from, state) do + {:reply, state.queue_size, state} + end + + @impl GenServer + def handle_info(:flush, state) do + new_state = + state + |> do_flush() + |> schedule_flush() + + {:noreply, new_state} + end + + @impl GenServer + def handle_info(_msg, state) do + {:noreply, state} + end + + @impl GenServer + def terminate(_reason, state) do + drain_all(state) + :ok + end + + # Private Functions + + defp schedule_flush(state) do + if state.timer_ref, do: Process.cancel_timer(state.timer_ref) + + timer_ref = Process.send_after(self(), :flush, get_flush_interval()) + %{state | timer_ref: timer_ref} + end + + defp do_flush(%{queue_size: 0} = state), do: state + + defp do_flush(state) do + batch_size = get_batch_size() + + {records, remaining_queue, remaining_size} = + dequeue_batch(state.queue, state.queue_size, batch_size) + + if length(records) > 0 do + Task.start(fn -> Exporter.export(records) end) + end + + %{state | queue: remaining_queue, queue_size: remaining_size} + end + + defp drain_all(%{queue_size: 0} = state), do: state + + defp drain_all(state) do + {records, remaining_queue, remaining_size} = + dequeue_batch(state.queue, state.queue_size, state.queue_size) + + if length(records) > 0 do + # Send synchronously during drain + Exporter.export(records) + end + + %{state | queue: remaining_queue, queue_size: remaining_size} + end + + defp dequeue_batch(queue, queue_size, batch_size) do + count = min(batch_size, queue_size) + + {records, new_queue} = + Enum.reduce(1..max(count, 1), {[], queue}, fn + _, {acc, q} when length(acc) >= count -> + {acc, q} + + _, {acc, q} -> + case :queue.out(q) do + {{:value, record}, new_q} -> {[record | acc], new_q} + {:empty, q} -> {acc, q} + end + end) + + {Enum.reverse(records), new_queue, queue_size - length(records)} + end + + defp get_batch_size, do: ScoutApm.Config.find(:logs_batch_size) || @default_batch_size + + defp get_max_queue_size, + do: ScoutApm.Config.find(:logs_max_queue_size) || @default_max_queue_size + + defp get_flush_interval, + do: ScoutApm.Config.find(:logs_flush_interval_ms) || @default_flush_interval_ms +end diff --git a/lib/scout_apm/logging/otlp/encoder.ex b/lib/scout_apm/logging/otlp/encoder.ex new file mode 100644 index 0000000..331ab9f --- /dev/null +++ b/lib/scout_apm/logging/otlp/encoder.ex @@ -0,0 +1,198 @@ +defmodule ScoutApm.Logging.OTLP.Encoder do + @moduledoc """ + Encodes log records into OTLP JSON format. + + Builds the full OTLP structure: + { + "resourceLogs": [{ + "resource": { "attributes": [...] }, + "scopeLogs": [{ + "scope": { "name": "scout_apm_elixir", "version": "..." }, + "logRecords": [...] + }] + }] + } + """ + + alias ScoutApm.Logging.OTLP.{Resource, Severity} + alias ScoutApm.Logging.LogRecord + + @scope_name "scout_apm_elixir" + + @doc """ + Encodes a list of LogRecord structs into OTLP JSON format. + """ + @spec encode([LogRecord.t()]) :: map() + def encode(log_records) when is_list(log_records) do + %{ + "resourceLogs" => [ + %{ + "resource" => %{ + "attributes" => Resource.build() + }, + "scopeLogs" => [ + %{ + "scope" => build_scope(), + "logRecords" => Enum.map(log_records, &encode_log_record/1) + } + ] + } + ] + } + end + + @doc """ + Encodes a single LogRecord struct into OTLP format. + """ + @spec encode_log_record(LogRecord.t()) :: map() + def encode_log_record(%LogRecord{} = record) do + base = %{ + "timeUnixNano" => record.timestamp_nanos, + "observedTimeUnixNano" => record.observed_timestamp_nanos, + "severityNumber" => Severity.to_number(record.severity), + "severityText" => Severity.to_text(record.severity), + "body" => encode_body(record.message) + } + + base + |> maybe_add_attributes(record.attributes) + |> maybe_add_trace_context(record) + |> maybe_add_dropped_count(record.dropped_attributes_count) + end + + # Private functions + + defp build_scope do + %{ + "name" => @scope_name, + "version" => get_version() + } + end + + defp get_version do + case :application.get_key(:scout_apm, :vsn) do + {:ok, vsn} -> List.to_string(vsn) + _ -> "unknown" + end + end + + defp encode_body(message) when is_binary(message) do + %{"stringValue" => message} + end + + defp encode_body(message) do + %{"stringValue" => inspect(message)} + end + + defp maybe_add_attributes(map, nil), do: map + defp maybe_add_attributes(map, attributes) when map_size(attributes) == 0, do: map + + defp maybe_add_attributes(map, attributes) do + encoded_attrs = + attributes + |> Enum.map(&encode_attribute/1) + |> Enum.reject(&is_nil/1) + + if length(encoded_attrs) > 0 do + Map.put(map, "attributes", encoded_attrs) + else + map + end + end + + defp encode_attribute({key, value}) when is_binary(key) do + encode_attribute_value(key, value) + end + + defp encode_attribute({key, value}) when is_atom(key) do + encode_attribute_value(Atom.to_string(key), value) + end + + defp encode_attribute(_), do: nil + + defp encode_attribute_value(key, value) when is_binary(value) do + %{"key" => key, "value" => %{"stringValue" => value}} + end + + defp encode_attribute_value(key, value) when is_integer(value) do + %{"key" => key, "value" => %{"intValue" => to_string(value)}} + end + + defp encode_attribute_value(key, value) when is_float(value) do + %{"key" => key, "value" => %{"doubleValue" => value}} + end + + defp encode_attribute_value(key, value) when is_boolean(value) do + %{"key" => key, "value" => %{"boolValue" => value}} + end + + defp encode_attribute_value(key, value) when is_atom(value) do + %{"key" => key, "value" => %{"stringValue" => Atom.to_string(value)}} + end + + defp encode_attribute_value(key, value) when is_list(value) do + # Encode as array value + encoded_values = + value + |> Enum.map(&encode_array_value/1) + |> Enum.reject(&is_nil/1) + + %{"key" => key, "value" => %{"arrayValue" => %{"values" => encoded_values}}} + end + + defp encode_attribute_value(key, value) when is_map(value) do + # Encode map as JSON string for simplicity + case Jason.encode(value) do + {:ok, json} -> %{"key" => key, "value" => %{"stringValue" => json}} + _ -> %{"key" => key, "value" => %{"stringValue" => inspect(value)}} + end + end + + defp encode_attribute_value(key, value) do + %{"key" => key, "value" => %{"stringValue" => inspect(value)}} + end + + defp encode_array_value(value) when is_binary(value), do: %{"stringValue" => value} + defp encode_array_value(value) when is_integer(value), do: %{"intValue" => to_string(value)} + defp encode_array_value(value) when is_float(value), do: %{"doubleValue" => value} + defp encode_array_value(value) when is_boolean(value), do: %{"boolValue" => value} + + defp encode_array_value(value) when is_atom(value), + do: %{"stringValue" => Atom.to_string(value)} + + defp encode_array_value(value), do: %{"stringValue" => inspect(value)} + + defp maybe_add_trace_context(map, %LogRecord{trace_id: nil}), do: map + defp maybe_add_trace_context(map, %LogRecord{span_id: nil}), do: map + + defp maybe_add_trace_context(map, %LogRecord{trace_id: trace_id, span_id: span_id}) do + map + |> Map.put("traceId", encode_trace_id(trace_id)) + |> Map.put("spanId", encode_span_id(span_id)) + end + + defp encode_trace_id(trace_id) when is_binary(trace_id), do: trace_id + + defp encode_trace_id(trace_id) when is_integer(trace_id) do + trace_id + |> Integer.to_string(16) + |> String.downcase() + |> String.pad_leading(32, "0") + end + + defp encode_span_id(span_id) when is_binary(span_id), do: span_id + + defp encode_span_id(span_id) when is_integer(span_id) do + span_id + |> Integer.to_string(16) + |> String.downcase() + |> String.pad_leading(16, "0") + end + + defp maybe_add_dropped_count(map, nil), do: map + defp maybe_add_dropped_count(map, 0), do: map + + defp maybe_add_dropped_count(map, count) do + Map.put(map, "droppedAttributesCount", count) + end +end diff --git a/lib/scout_apm/logging/otlp/exporter.ex b/lib/scout_apm/logging/otlp/exporter.ex new file mode 100644 index 0000000..ba04ca6 --- /dev/null +++ b/lib/scout_apm/logging/otlp/exporter.ex @@ -0,0 +1,117 @@ +defmodule ScoutApm.Logging.OTLP.Exporter do + @moduledoc """ + HTTP transport for sending logs to an OTLP collector. + + Sends log records via HTTP POST to the /v1/logs endpoint. + Supports gzip compression for payloads over 1KB. + """ + + alias ScoutApm.Logging.OTLP.Encoder + alias ScoutApm.Logging.LogRecord + + @logs_endpoint "/v1/logs" + @compression_threshold 1024 + + @doc """ + Exports a batch of log records to the configured OTLP endpoint. + Returns :ok on success or {:error, reason} on failure. + """ + @spec export([LogRecord.t()]) :: :ok | {:error, term()} + def export([]), do: :ok + + def export(log_records) when is_list(log_records) do + payload = Encoder.encode(log_records) + + case Jason.encode(payload) do + {:ok, json} -> + {body, content_encoding} = maybe_compress(json) + + url = build_url() + headers = build_headers(content_encoding) + + ScoutApm.Logger.log(:debug, "OTLP logs export URL: #{url}") + ScoutApm.Logger.log(:debug, "OTLP logs export headers: #{inspect(headers)}") + + ScoutApm.Logger.log( + :debug, + "OTLP logs export payload (#{byte_size(json)} bytes): #{json}" + ) + + do_http_send(body, content_encoding, length(log_records)) + + {:error, reason} -> + ScoutApm.Logger.log(:debug, "Failed to encode log payload: #{inspect(reason)}") + {:error, {:encode_error, reason}} + end + end + + # Private functions + + defp maybe_compress(json) when byte_size(json) > @compression_threshold do + {:zlib.gzip(json), "gzip"} + end + + defp maybe_compress(json) do + {json, nil} + end + + defp do_http_send(body, content_encoding, log_count) do + url = build_url() + headers = build_headers(content_encoding) + + case :hackney.request(:post, url, headers, body, [:with_body]) do + {:ok, status, _headers, _body} when status < 300 -> + ScoutApm.Logger.log(:debug, "Successfully sent #{log_count} logs to OTLP collector") + :ok + + {:ok, status, _headers, response_body} -> + ScoutApm.Logger.log( + :debug, + "Error sending logs to OTLP collector. Status: #{status}, Body: #{inspect(response_body)}" + ) + + {:error, {:http_error, status}} + + {:error, reason} -> + ScoutApm.Logger.log(:debug, "Error sending logs to OTLP collector: #{inspect(reason)}") + {:error, reason} + end + end + + defp build_url do + endpoint = get_endpoint() + + # Ensure endpoint doesn't have trailing slash + endpoint = String.trim_trailing(endpoint, "/") + "#{endpoint}#{@logs_endpoint}" + end + + defp get_endpoint do + ScoutApm.Config.find(:logs_endpoint) || "https://otlp.scoutotel.com:4318" + end + + defp build_headers(content_encoding) do + base_headers = [ + {"Content-Type", "application/json"}, + {"x-scout-key", get_ingest_key()}, + {"User-Agent", "scout_apm_elixir/#{get_version()}"} + ] + + if content_encoding do + [{"Content-Encoding", content_encoding} | base_headers] + else + base_headers + end + end + + defp get_ingest_key do + ScoutApm.Config.find(:logs_ingest_key) || ScoutApm.Config.find(:key) || "" + end + + defp get_version do + case :application.get_key(:scout_apm, :vsn) do + {:ok, vsn} -> List.to_string(vsn) + _ -> "unknown" + end + end +end diff --git a/lib/scout_apm/logging/otlp/resource.ex b/lib/scout_apm/logging/otlp/resource.ex new file mode 100644 index 0000000..9040eb6 --- /dev/null +++ b/lib/scout_apm/logging/otlp/resource.ex @@ -0,0 +1,113 @@ +defmodule ScoutApm.Logging.OTLP.Resource do + @moduledoc """ + Builds OTLP Resource attributes for log records. + + The Resource represents the entity producing telemetry and includes + attributes like service name, version, host, and environment. + """ + + @doc """ + Builds the resource attributes map for OTLP export. + Returns a list of attribute maps in OTLP format. + """ + @spec build() :: [map()] + def build do + attributes = [ + {"service.name", get_service_name()}, + {"service.version", get_service_version()}, + {"telemetry.sdk.name", "scout_apm_elixir"}, + {"telemetry.sdk.version", get_sdk_version()}, + {"telemetry.sdk.language", "elixir"}, + {"host.name", get_hostname()}, + {"deployment.environment", get_environment()} + ] + + attributes + |> Enum.filter(fn {_key, value} -> value != nil and value != "" end) + |> Enum.map(&to_otlp_attribute/1) + end + + @doc """ + Converts a {key, value} tuple to OTLP attribute format. + """ + @spec to_otlp_attribute({String.t(), any()}) :: map() + def to_otlp_attribute({key, value}) when is_binary(value) do + %{"key" => key, "value" => %{"stringValue" => value}} + end + + def to_otlp_attribute({key, value}) when is_integer(value) do + %{"key" => key, "value" => %{"intValue" => to_string(value)}} + end + + def to_otlp_attribute({key, value}) when is_float(value) do + %{"key" => key, "value" => %{"doubleValue" => value}} + end + + def to_otlp_attribute({key, value}) when is_boolean(value) do + %{"key" => key, "value" => %{"boolValue" => value}} + end + + def to_otlp_attribute({key, value}) when is_atom(value) do + %{"key" => key, "value" => %{"stringValue" => Atom.to_string(value)}} + end + + def to_otlp_attribute({key, value}) do + %{"key" => key, "value" => %{"stringValue" => inspect(value)}} + end + + # Private functions + + defp get_service_name do + ScoutApm.Config.find(:name) || get_app_name() + end + + defp get_app_name do + case Application.get_application(__MODULE__) do + nil -> "unknown" + app -> Atom.to_string(app) + end + end + + defp get_service_version do + ScoutApm.Config.find(:revision_sha) || get_app_version() + end + + defp get_app_version do + case :application.get_key(:scout_apm, :vsn) do + {:ok, vsn} -> List.to_string(vsn) + _ -> nil + end + end + + defp get_sdk_version do + case :application.get_key(:scout_apm, :vsn) do + {:ok, vsn} -> List.to_string(vsn) + _ -> "unknown" + end + end + + defp get_hostname do + ScoutApm.Cache.hostname() || get_system_hostname() + end + + defp get_system_hostname do + case :inet.gethostname() do + {:ok, hostname} -> List.to_string(hostname) + _ -> nil + end + end + + defp get_environment do + case ScoutApm.Config.find(:environment) do + nil -> + if function_exported?(Mix, :env, 0) do + Mix.env() |> to_string() + else + "production" + end + + env -> + to_string(env) + end + end +end diff --git a/lib/scout_apm/logging/otlp/severity.ex b/lib/scout_apm/logging/otlp/severity.ex new file mode 100644 index 0000000..e4cdadb --- /dev/null +++ b/lib/scout_apm/logging/otlp/severity.ex @@ -0,0 +1,63 @@ +defmodule ScoutApm.Logging.OTLP.Severity do + @moduledoc """ + Maps Elixir Logger levels to OpenTelemetry severity numbers and text. + + OTLP Severity Numbers (from OpenTelemetry specification): + - 1-4: TRACE + - 5-8: DEBUG + - 9-12: INFO + - 13-16: WARN + - 17-20: ERROR + - 21-24: FATAL + """ + + @type level :: + :emergency | :alert | :critical | :error | :warning | :warn | :notice | :info | :debug + + @doc """ + Converts an Elixir Logger level to an OTLP severity number. + """ + @spec to_number(level()) :: pos_integer() + def to_number(:emergency), do: 21 + def to_number(:alert), do: 21 + def to_number(:critical), do: 21 + def to_number(:error), do: 17 + def to_number(:warning), do: 13 + def to_number(:warn), do: 13 + def to_number(:notice), do: 11 + def to_number(:info), do: 9 + def to_number(:debug), do: 5 + def to_number(_), do: 0 + + @doc """ + Converts an Elixir Logger level to an OTLP severity text string. + """ + @spec to_text(level()) :: String.t() + def to_text(:emergency), do: "FATAL" + def to_text(:alert), do: "FATAL" + def to_text(:critical), do: "FATAL" + def to_text(:error), do: "ERROR" + def to_text(:warning), do: "WARN" + def to_text(:warn), do: "WARN" + def to_text(:notice), do: "INFO2" + def to_text(:info), do: "INFO" + def to_text(:debug), do: "DEBUG" + def to_text(_), do: "UNSPECIFIED" + + @doc """ + Compares two log levels. Returns true if level1 is at or above level2. + Used for filtering logs by minimum level. + """ + @spec meets_level?(level(), level()) :: boolean() + def meets_level?(level1, level2) do + to_number(level1) >= to_number(level2) + end + + @doc """ + Returns the list of all supported Elixir log levels in order of severity (highest first). + """ + @spec levels() :: [level()] + def levels do + [:emergency, :alert, :critical, :error, :warning, :notice, :info, :debug] + end +end diff --git a/lib/scout_apm/metric_set.ex b/lib/scout_apm/metric_set.ex index e88830f..2519188 100644 --- a/lib/scout_apm/metric_set.ex +++ b/lib/scout_apm/metric_set.ex @@ -105,9 +105,7 @@ defmodule ScoutApm.MetricSet do defp scoped_key(metric, %{compare_desc: compare_desc}) do case compare_desc do true -> - "#{metric.type}/#{metric.name}/scope/#{metric.scope[:type]}/#{metric.scope[:name]}/desc/#{ - metric.desc - }" + "#{metric.type}/#{metric.name}/scope/#{metric.scope[:type]}/#{metric.scope[:name]}/desc/#{metric.desc}" false -> "#{metric.type}/#{metric.name}/scope/#{metric.scope[:type]}/#{metric.scope[:name]}" diff --git a/lib/scout_apm/payload/metadata.ex b/lib/scout_apm/payload/metadata.ex index 0e72da0..f2e1465 100644 --- a/lib/scout_apm/payload/metadata.ex +++ b/lib/scout_apm/payload/metadata.ex @@ -28,7 +28,7 @@ defmodule ScoutApm.Payload.Metadata do payload_version: 1, agent_version: ScoutApm.Utils.agent_version(), agent_time: timestamp |> DateTime.from_naive!("Etc/UTC") |> DateTime.to_iso8601(), - agent_pid: System.get_pid() |> String.to_integer(), + agent_pid: System.pid() |> String.to_integer(), platform: "elixir", platform_version: System.version(), language: "elixir", diff --git a/lib/scout_apm/plugs/controller_timer.ex b/lib/scout_apm/plugs/controller_timer.ex index a42b77d..2787176 100644 --- a/lib/scout_apm/plugs/controller_timer.ex +++ b/lib/scout_apm/plugs/controller_timer.ex @@ -8,7 +8,9 @@ defmodule ScoutApm.Plugs.ControllerTimer do def call(conn, opts) do if !ignore_uri?(conn.request_path) do queue_time = get_queue_time_diff_nanoseconds(conn) - TrackedRequest.start_layer("Controller", action_name(conn, opts)) + name = action_name(conn, opts) + TrackedRequest.start_layer("Controller", name) + ScoutApm.Logging.ContextExtractor.stash_context("Controller", name) if queue_time do Context.add("scout.queue_time_ns", "#{queue_time}") diff --git a/lib/scout_apm/tracing.ex b/lib/scout_apm/tracing.ex index 2732aae..3ac5d58 100644 --- a/lib/scout_apm/tracing.ex +++ b/lib/scout_apm/tracing.ex @@ -105,9 +105,10 @@ defmodule ScoutApm.Tracing do try do (fn -> unquote(block) end).() rescue - e in RuntimeError -> - # TODO - Add real error tracking - raise e + e -> + ScoutApm.Error.capture(e, stacktrace: __STACKTRACE__) + TrackedRequest.mark_error() + reraise e, __STACKTRACE__ after TrackedRequest.stop_layer() end diff --git a/lib/scout_apm/tracing/annotations.ex b/lib/scout_apm/tracing/annotations.ex index 8b13789..e69de29 100644 --- a/lib/scout_apm/tracing/annotations.ex +++ b/lib/scout_apm/tracing/annotations.ex @@ -1 +0,0 @@ - diff --git a/mix.exs b/mix.exs index 50f7473..d4ce4c3 100644 --- a/mix.exs +++ b/mix.exs @@ -4,7 +4,7 @@ defmodule ScoutApm.Mixfile do def project do [ app: :scout_apm, - version: "1.0.7", + version: "2.0.0-rc.1", elixir: "~> 1.14", build_embedded: Mix.env() == :prod, start_permanent: Mix.env() == :prod, @@ -27,30 +27,28 @@ defmodule ScoutApm.Mixfile do defp deps do [ - {:plug, "~>1.0"}, + {:plug, "~> 1.0"}, {:jason, "~> 1.0"}, # We only use `request/5` from hackney, which hasn't changed in the 1.0 line. {:hackney, "~> 1.0"}, - {:approximate_histogram, "~>0.1.1"}, + {:approximate_histogram, "~> 0.1.1"}, {:telemetry, "~> 1.0", optional: true}, - ######################### - # Dev & Testing Deps + # Optional Phoenix instrumentation dependencies + {:phoenix, "~> 1.6", optional: true}, + {:phoenix_html, "~> 3.0 or ~> 4.0", optional: true}, + {:phoenix_live_view, "~> 0.18 or ~> 1.0", optional: true}, + # Dev & Testing Deps {:ex_doc, ">= 0.0.0", only: [:dev]}, - {:credo, "~> 0.5", only: [:dev, :test]}, - {:dialyxir, "~> 0.5", only: [:dev], runtime: false}, - - # TODO: Should this be in the dev-only dependencies? It is needed for dialyzer to complete correctly. - {:phoenix, "~> 1.0", only: [:dev, :test]}, - {:phoenix_slime, "~> 0.9.0", only: [:dev, :test]} + {:dialyxir, "~> 0.5", only: [:dev], runtime: false} ] end defp description() do """ - ScoutAPM agent for Phoenix & Elixir projects. For more information, visit https://scoutapm.com/elixir. + ScoutAPM agent for Phoenix & Elixir projects. For more information, visit https://www.scoutapm.com/agents/elixir-phoenix-monitoring. """ end diff --git a/mix.lock b/mix.lock index f1416d7..2c2c782 100644 --- a/mix.lock +++ b/mix.lock @@ -1,37 +1,30 @@ %{ "approximate_histogram": {:hex, :approximate_histogram, "0.1.1", "198eb36681e763ed4baab6ca0682acec4ef642f60ba272f251d3059052f4f378", [:mix], [], "hexpm", "6cce003d09656efbfe80b4a50f19e6c1f8eaf1424f08e4a96036b340fc67019d"}, - "bunt": {:hex, :bunt, "0.2.1", "e2d4792f7bc0ced7583ab54922808919518d0e57ee162901a16a1b6664ef3b14", [:mix], [], "hexpm", "a330bfb4245239787b15005e66ae6845c9cd524a288f0d141c148b02603777a5"}, - "castore": {:hex, :castore, "0.1.18", "deb5b9ab02400561b6f5708f3e7660fc35ca2d51bfc6a940d2f513f89c2975fc", [:mix], [], "hexpm", "61bbaf6452b782ef80b33cdb45701afbcf0a918a45ebe7e73f1130d661e66a06"}, - "certifi": {:hex, :certifi, "2.9.0", "6f2a475689dd47f19fb74334859d460a2dc4e3252a3324bd2111b8f0429e7e21", [:rebar3], [], "hexpm", "266da46bdb06d6c6d35fde799bcb28d36d985d424ad7c08b5bb48f5b5cdd4641"}, - "cowboy": {:hex, :cowboy, "1.1.2", "61ac29ea970389a88eca5a65601460162d370a70018afe6f949a29dca91f3bb0", [:rebar3], [{:cowlib, "~> 1.0.2", [hex: :cowlib, repo: "hexpm", optional: false]}, {:ranch, "~> 1.3.2", [hex: :ranch, repo: "hexpm", optional: false]}], "hexpm", "f4763bbe08233eceed6f24bc4fcc8d71c17cfeafa6439157c57349aa1bb4f17c"}, - "cowlib": {:hex, :cowlib, "1.0.2", "9d769a1d062c9c3ac753096f868ca121e2730b9a377de23dec0f7e08b1df84ee", [:make], [], "hexpm", "db622da03aa039e6366ab953e31186cc8190d32905e33788a1acb22744e6abd2"}, - "credo": {:hex, :credo, "0.10.2", "03ad3a1eff79a16664ed42fc2975b5e5d0ce243d69318060c626c34720a49512", [:mix], [{:bunt, "~> 0.2.0", [hex: :bunt, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: false]}], "hexpm", "539596b6774069260d5938aa73042a2f5157e1c0215aa35f5a53d83889546d14"}, + "certifi": {:hex, :certifi, "2.15.0", "0e6e882fcdaaa0a5a9f2b3db55b1394dba07e8d6d9bcad08318fb604c6839712", [:rebar3], [], "hexpm", "b147ed22ce71d72eafdad94f055165c1c182f61a2ff49df28bcc71d1d5b94a60"}, "dialyxir": {:hex, :dialyxir, "0.5.1", "b331b091720fd93e878137add264bac4f644e1ddae07a70bf7062c7862c4b952", [:mix], [], "hexpm", "6c32a70ed5d452c6650916555b1f96c79af5fc4bf286997f8b15f213de786f73"}, - "earmark": {:hex, :earmark, "1.4.0", "397e750b879df18198afc66505ca87ecf6a96645545585899f6185178433cc09", [:mix], [], "hexpm", "4bedcec35de03b5f559fd2386be24d08f7637c374d3a85d3fe0911eecdae838a"}, - "earmark_parser": {:hex, :earmark_parser, "1.4.28", "0bf6546eb7cd6185ae086cbc5d20cd6dbb4b428aad14c02c49f7b554484b4586", [:mix], [], "hexpm", "501cef12286a3231dc80c81352a9453decf9586977f917a96e619293132743fb"}, - "ex_doc": {:hex, :ex_doc, "0.29.0", "4a1cb903ce746aceef9c1f9ae8a6c12b742a5461e6959b9d3b24d813ffbea146", [:mix], [{:earmark_parser, "~> 1.4.19", [hex: :earmark_parser, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}, {:makeup_erlang, "~> 0.1", [hex: :makeup_erlang, repo: "hexpm", optional: false]}], "hexpm", "f096adb8bbca677d35d278223361c7792d496b3fc0d0224c9d4bc2f651af5db1"}, - "hackney": {:hex, :hackney, "1.18.1", "f48bf88f521f2a229fc7bae88cf4f85adc9cd9bcf23b5dc8eb6a1788c662c4f6", [:rebar3], [{:certifi, "~>2.9.0", [hex: :certifi, repo: "hexpm", optional: false]}, {:idna, "~>6.1.0", [hex: :idna, repo: "hexpm", optional: false]}, {:metrics, "~>1.0.0", [hex: :metrics, repo: "hexpm", optional: false]}, {:mimerl, "~>1.1", [hex: :mimerl, repo: "hexpm", optional: false]}, {:parse_trans, "3.3.1", [hex: :parse_trans, repo: "hexpm", optional: false]}, {:ssl_verify_fun, "~>1.1.0", [hex: :ssl_verify_fun, repo: "hexpm", optional: false]}, {:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "a4ecdaff44297e9b5894ae499e9a070ea1888c84afdd1fd9b7b2bc384950128e"}, - "idna": {:hex, :idna, "6.1.1", "8a63070e9f7d0c62eb9d9fcb360a7de382448200fbbd1b106cc96d3d8099df8d", [:rebar3], [{:unicode_util_compat, "~>0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "92376eb7894412ed19ac475e4a86f7b413c1b9fbb5bd16dccd57934157944cea"}, - "jason": {:hex, :jason, "1.4.0", "e855647bc964a44e2f67df589ccf49105ae039d4179db7f6271dfd3843dc27e6", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "79a3791085b2a0f743ca04cec0f7be26443738779d09302e01318f97bdb82121"}, - "makeup": {:hex, :makeup, "1.1.0", "6b67c8bc2882a6b6a445859952a602afc1a41c2e08379ca057c0f525366fc3ca", [:mix], [{:nimble_parsec, "~> 1.2.2 or ~> 1.3", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "0a45ed501f4a8897f580eabf99a2e5234ea3e75a4373c8a52824f6e873be57a6"}, - "makeup_elixir": {:hex, :makeup_elixir, "0.16.0", "f8c570a0d33f8039513fbccaf7108c5d750f47d8defd44088371191b76492b0b", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}, {:nimble_parsec, "~> 1.2.3", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "28b2cbdc13960a46ae9a8858c4bebdec3c9a6d7b4b9e7f4ed1502f8159f338e7"}, - "makeup_erlang": {:hex, :makeup_erlang, "0.1.1", "3fcb7f09eb9d98dc4d208f49cc955a34218fc41ff6b84df7c75b3e6e533cc65f", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "174d0809e98a4ef0b3309256cbf97101c6ec01c4ab0b23e926a9e17df2077cbb"}, + "earmark_parser": {:hex, :earmark_parser, "1.4.44", "f20830dd6b5c77afe2b063777ddbbff09f9759396500cdbe7523efd58d7a339c", [:mix], [], "hexpm", "4778ac752b4701a5599215f7030989c989ffdc4f6df457c5f36938cc2d2a2750"}, + "ex_doc": {:hex, :ex_doc, "0.40.0", "2635974389b80fd3ca61b0f993d459dad05b4a8f9b069dcfbbc5f6a8a6aef60e", [:mix], [{:earmark_parser, "~> 1.4.44", [hex: :earmark_parser, repo: "hexpm", optional: false]}, {:makeup_c, ">= 0.1.0", [hex: :makeup_c, repo: "hexpm", optional: true]}, {:makeup_elixir, "~> 0.14 or ~> 1.0", [hex: :makeup_elixir, repo: "hexpm", optional: false]}, {:makeup_erlang, "~> 0.1 or ~> 1.0", [hex: :makeup_erlang, repo: "hexpm", optional: false]}, {:makeup_html, ">= 0.1.0", [hex: :makeup_html, repo: "hexpm", optional: true]}], "hexpm", "c040735250e2752b6e1102eeb4aa3f1dca74c316db873ae09f955d42136e7e5b"}, + "hackney": {:hex, :hackney, "1.25.0", "390e9b83f31e5b325b9f43b76e1a785cbdb69b5b6cd4e079aa67835ded046867", [:rebar3], [{:certifi, "~> 2.15.0", [hex: :certifi, repo: "hexpm", optional: false]}, {:idna, "~> 6.1.0", [hex: :idna, repo: "hexpm", optional: false]}, {:metrics, "~> 1.0.0", [hex: :metrics, repo: "hexpm", optional: false]}, {:mimerl, "~> 1.4", [hex: :mimerl, repo: "hexpm", optional: false]}, {:parse_trans, "3.4.1", [hex: :parse_trans, repo: "hexpm", optional: false]}, {:ssl_verify_fun, "~> 1.1.0", [hex: :ssl_verify_fun, repo: "hexpm", optional: false]}, {:unicode_util_compat, "~> 0.7.1", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "7209bfd75fd1f42467211ff8f59ea74d6f2a9e81cbcee95a56711ee79fd6b1d4"}, + "idna": {:hex, :idna, "6.1.1", "8a63070e9f7d0c62eb9d9fcb360a7de382448200fbbd1b106cc96d3d8099df8d", [:rebar3], [{:unicode_util_compat, "~> 0.7.0", [hex: :unicode_util_compat, repo: "hexpm", optional: false]}], "hexpm", "92376eb7894412ed19ac475e4a86f7b413c1b9fbb5bd16dccd57934157944cea"}, + "jason": {:hex, :jason, "1.4.4", "b9226785a9aa77b6857ca22832cffa5d5011a667207eb2a0ad56adb5db443b8a", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "c5eb0cab91f094599f94d55bc63409236a8ec69a21a67814529e8d5f6cc90b3b"}, + "makeup": {:hex, :makeup, "1.2.1", "e90ac1c65589ef354378def3ba19d401e739ee7ee06fb47f94c687016e3713d1", [:mix], [{:nimble_parsec, "~> 1.4", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "d36484867b0bae0fea568d10131197a4c2e47056a6fbe84922bf6ba71c8d17ce"}, + "makeup_elixir": {:hex, :makeup_elixir, "1.0.1", "e928a4f984e795e41e3abd27bfc09f51db16ab8ba1aebdba2b3a575437efafc2", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}, {:nimble_parsec, "~> 1.2.3 or ~> 1.3", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "7284900d412a3e5cfd97fdaed4f5ed389b8f2b4cb49efc0eb3bd10e2febf9507"}, + "makeup_erlang": {:hex, :makeup_erlang, "1.0.3", "4252d5d4098da7415c390e847c814bad3764c94a814a0b4245176215615e1035", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "953297c02582a33411ac6208f2c6e55f0e870df7f80da724ed613f10e6706afd"}, "metrics": {:hex, :metrics, "1.0.1", "25f094dea2cda98213cecc3aeff09e940299d950904393b2a29d191c346a8486", [:rebar3], [], "hexpm", "69b09adddc4f74a40716ae54d140f93beb0fb8978d8636eaded0c31b6f099f16"}, - "mime": {:hex, :mime, "2.0.3", "3676436d3d1f7b81b5a2d2bd8405f412c677558c81b1c92be58c00562bb59095", [:mix], [], "hexpm", "27a30bf0db44d25eecba73755acf4068cbfe26a4372f9eb3e4ea3a45956bff6b"}, - "mimerl": {:hex, :mimerl, "1.2.0", "67e2d3f571088d5cfd3e550c383094b47159f3eee8ffa08e64106cdf5e981be3", [:rebar3], [], "hexpm", "f278585650aa581986264638ebf698f8bb19df297f66ad91b18910dfc6e19323"}, - "nimble_parsec": {:hex, :nimble_parsec, "1.2.3", "244836e6e3f1200c7f30cb56733fd808744eca61fd182f731eac4af635cc6d0b", [:mix], [], "hexpm", "c8d789e39b9131acf7b99291e93dae60ab48ef14a7ee9d58c6964f59efb570b0"}, - "parse_trans": {:hex, :parse_trans, "3.3.1", "16328ab840cc09919bd10dab29e431da3af9e9e7e7e6f0089dd5a2d2820011d8", [:rebar3], [], "hexpm", "07cd9577885f56362d414e8c4c4e6bdf10d43a8767abb92d24cbe8b24c54888b"}, - "phoenix": {:hex, :phoenix, "1.6.14", "57678366dc1d5bad49832a0fc7f12c2830c10d3eacfad681bfe9602cd4445f04", [:mix], [{:castore, ">= 0.0.0", [hex: :castore, repo: "hexpm", optional: false]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: true]}, {:phoenix_pubsub, "~> 2.0", [hex: :phoenix_pubsub, repo: "hexpm", optional: false]}, {:phoenix_view, "~> 1.0", [hex: :phoenix_view, repo: "hexpm", optional: false]}, {:plug, "~> 1.10", [hex: :plug, repo: "hexpm", optional: false]}, {:plug_cowboy, "~> 2.2", [hex: :plug_cowboy, repo: "hexpm", optional: true]}, {:plug_crypto, "~> 1.2", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "d48c0da00b3d4cd1aad6055387917491af9f6e1f1e96cedf6c6b7998df9dba26"}, - "phoenix_html": {:hex, :phoenix_html, "2.14.3", "51f720d0d543e4e157ff06b65de38e13303d5778a7919bcc696599e5934271b8", [:mix], [{:plug, "~> 1.5", [hex: :plug, repo: "hexpm", optional: false]}], "hexpm", "efd697a7fff35a13eeeb6b43db884705cba353a1a41d127d118fda5f90c8e80f"}, - "phoenix_pubsub": {:hex, :phoenix_pubsub, "2.1.1", "ba04e489ef03763bf28a17eb2eaddc2c20c6d217e2150a61e3298b0f4c2012b5", [:mix], [], "hexpm", "81367c6d1eea5878ad726be80808eb5a787a23dee699f96e72b1109c57cdd8d9"}, - "phoenix_slime": {:hex, :phoenix_slime, "0.9.0", "1dbebe18757d57cfd2e62314c04c17d9acc7d31e2ca9387dd3fdeebe52fbd4bd", [:mix], [{:cowboy, "~> 1.0", [hex: :cowboy, repo: "hexpm", optional: false]}, {:phoenix, "~> 1.3-rc", [hex: :phoenix, repo: "hexpm", optional: false]}, {:phoenix_html, "~> 2.6", [hex: :phoenix_html, repo: "hexpm", optional: false]}, {:slime, "~> 0.16", [hex: :slime, repo: "hexpm", optional: false]}], "hexpm", "1028ba679568b6a3d4597865ca4456d0469802927efc73220a5396a42f218b1b"}, - "phoenix_view": {:hex, :phoenix_view, "1.1.2", "1b82764a065fb41051637872c7bd07ed2fdb6f5c3bd89684d4dca6e10115c95a", [:mix], [{:phoenix_html, "~> 2.14.2 or ~> 3.0", [hex: :phoenix_html, repo: "hexpm", optional: true]}], "hexpm", "7ae90ad27b09091266f6adbb61e1d2516a7c3d7062c6789d46a7554ec40f3a56"}, - "plug": {:hex, :plug, "1.13.6", "187beb6b67c6cec50503e940f0434ea4692b19384d47e5fdfd701e93cadb4cc2", [:mix], [{:mime, "~> 1.0 or ~> 2.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.1.1 or ~> 1.2", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4.3 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "02b9c6b9955bce92c829f31d6284bf53c591ca63c4fb9ff81dfd0418667a34ff"}, - "plug_crypto": {:hex, :plug_crypto, "1.2.3", "8f77d13aeb32bfd9e654cb68f0af517b371fb34c56c9f2b58fe3df1235c1251a", [:mix], [], "hexpm", "b5672099c6ad5c202c45f5a403f21a3411247f164e4a8fab056e5cd8a290f4a2"}, - "proper": {:hex, :proper, "1.1.1-beta", "5eef3fa0cae017ecb4bf6fd6a144349a048e999223a4f1e98ce372ff1772edd3", [:rebar3], []}, - "ranch": {:hex, :ranch, "1.3.2", "e4965a144dc9fbe70e5c077c65e73c57165416a901bd02ea899cfd95aa890986", [:rebar3], [], "hexpm", "6e56493a862433fccc3aca3025c946d6720d8eedf6e3e6fb911952a7071c357f"}, - "slime": {:hex, :slime, "0.16.0", "4f9c677ca37b2817cd10422ecb42c524fe904d3630acf242b81dfe189900272a", [:mix], [], "hexpm", "9a8c51853302df424aea6ce590e5f67ad8ba9581dd62ecb0c685bcf462c4cd79"}, - "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.6", "cf344f5692c82d2cd7554f5ec8fd961548d4fd09e7d22f5b62482e5aeaebd4b0", [:make, :mix, :rebar3], [], "hexpm", "bdb0d2471f453c88ff3908e7686f86f9be327d065cc1ec16fa4540197ea04680"}, - "telemetry": {:hex, :telemetry, "1.2.1", "68fdfe8d8f05a8428483a97d7aab2f268aaff24b49e0f599faa091f1d4e7f61c", [:rebar3], [], "hexpm", "dad9ce9d8effc621708f99eac538ef1cbe05d6a874dd741de2e689c47feafed5"}, - "unicode_util_compat": {:hex, :unicode_util_compat, "0.7.0", "bc84380c9ab48177092f43ac89e4dfa2c6d62b40b8bd132b1059ecc7232f9a78", [:rebar3], [], "hexpm", "25eee6d67df61960cf6a794239566599b09e17e668d3700247bc498638152521"}, + "mime": {:hex, :mime, "2.0.7", "b8d739037be7cd402aee1ba0306edfdef982687ee7e9859bee6198c1e7e2f128", [:mix], [], "hexpm", "6171188e399ee16023ffc5b76ce445eb6d9672e2e241d2df6050f3c771e80ccd"}, + "mimerl": {:hex, :mimerl, "1.4.0", "3882a5ca67fbbe7117ba8947f27643557adec38fa2307490c4c4207624cb213b", [:rebar3], [], "hexpm", "13af15f9f68c65884ecca3a3891d50a7b57d82152792f3e19d88650aa126b144"}, + "nimble_parsec": {:hex, :nimble_parsec, "1.4.2", "8efba0122db06df95bfaa78f791344a89352ba04baedd3849593bfce4d0dc1c6", [:mix], [], "hexpm", "4b21398942dda052b403bbe1da991ccd03a053668d147d53fb8c4e0efe09c973"}, + "parse_trans": {:hex, :parse_trans, "3.4.1", "6e6aa8167cb44cc8f39441d05193be6e6f4e7c2946cb2759f015f8c56b76e5ff", [:rebar3], [], "hexpm", "620a406ce75dada827b82e453c19cf06776be266f5a67cff34e1ef2cbb60e49a"}, + "phoenix": {:hex, :phoenix, "1.8.3", "49ac5e485083cb1495a905e47eb554277bdd9c65ccb4fc5100306b350151aa95", [:mix], [{:bandit, "~> 1.0", [hex: :bandit, repo: "hexpm", optional: true]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: true]}, {:phoenix_pubsub, "~> 2.1", [hex: :phoenix_pubsub, repo: "hexpm", optional: false]}, {:phoenix_template, "~> 1.0", [hex: :phoenix_template, repo: "hexpm", optional: false]}, {:phoenix_view, "~> 2.0", [hex: :phoenix_view, repo: "hexpm", optional: true]}, {:plug, "~> 1.14", [hex: :plug, repo: "hexpm", optional: false]}, {:plug_cowboy, "~> 2.7", [hex: :plug_cowboy, repo: "hexpm", optional: true]}, {:plug_crypto, "~> 1.2 or ~> 2.0", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}, {:websock_adapter, "~> 0.5.3", [hex: :websock_adapter, repo: "hexpm", optional: false]}], "hexpm", "36169f95cc2e155b78be93d9590acc3f462f1e5438db06e6248613f27c80caec"}, + "phoenix_html": {:hex, :phoenix_html, "4.3.0", "d3577a5df4b6954cd7890c84d955c470b5310bb49647f0a114a6eeecc850f7ad", [:mix], [], "hexpm", "3eaa290a78bab0f075f791a46a981bbe769d94bc776869f4f3063a14f30497ad"}, + "phoenix_live_view": {:hex, :phoenix_live_view, "1.1.20", "4f20850ee700b309b21906a0e510af1b916b454b4f810fb8581ada016eb42dfc", [:mix], [{:igniter, ">= 0.6.16 and < 1.0.0-0", [hex: :igniter, repo: "hexpm", optional: true]}, {:jason, "~> 1.0", [hex: :jason, repo: "hexpm", optional: true]}, {:lazy_html, "~> 0.1.0", [hex: :lazy_html, repo: "hexpm", optional: true]}, {:phoenix, "~> 1.6.15 or ~> 1.7.0 or ~> 1.8.0-rc", [hex: :phoenix, repo: "hexpm", optional: false]}, {:phoenix_html, "~> 3.3 or ~> 4.0", [hex: :phoenix_html, repo: "hexpm", optional: false]}, {:phoenix_template, "~> 1.0", [hex: :phoenix_template, repo: "hexpm", optional: false]}, {:phoenix_view, "~> 2.0", [hex: :phoenix_view, repo: "hexpm", optional: true]}, {:plug, "~> 1.15", [hex: :plug, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4.2 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "c16abd605a21f778165cb0079946351ef20ef84eb1ef467a862fb9a173b1d27d"}, + "phoenix_pubsub": {:hex, :phoenix_pubsub, "2.2.0", "ff3a5616e1bed6804de7773b92cbccfc0b0f473faf1f63d7daf1206c7aeaaa6f", [:mix], [], "hexpm", "adc313a5bf7136039f63cfd9668fde73bba0765e0614cba80c06ac9460ff3e96"}, + "phoenix_template": {:hex, :phoenix_template, "1.0.4", "e2092c132f3b5e5b2d49c96695342eb36d0ed514c5b252a77048d5969330d639", [:mix], [{:phoenix_html, "~> 2.14.2 or ~> 3.0 or ~> 4.0", [hex: :phoenix_html, repo: "hexpm", optional: true]}], "hexpm", "2c0c81f0e5c6753faf5cca2f229c9709919aba34fab866d3bc05060c9c444206"}, + "plug": {:hex, :plug, "1.19.1", "09bac17ae7a001a68ae393658aa23c7e38782be5c5c00c80be82901262c394c0", [:mix], [{:mime, "~> 1.0 or ~> 2.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.1.1 or ~> 1.2 or ~> 2.0", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4.3 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "560a0017a8f6d5d30146916862aaf9300b7280063651dd7e532b8be168511e62"}, + "plug_crypto": {:hex, :plug_crypto, "2.1.1", "19bda8184399cb24afa10be734f84a16ea0a2bc65054e23a62bb10f06bc89491", [:mix], [], "hexpm", "6470bce6ffe41c8bd497612ffde1a7e4af67f36a15eea5f921af71cf3e11247c"}, + "ssl_verify_fun": {:hex, :ssl_verify_fun, "1.1.7", "354c321cf377240c7b8716899e182ce4890c5938111a1296add3ec74cf1715df", [:make, :mix, :rebar3], [], "hexpm", "fe4c190e8f37401d30167c8c405eda19469f34577987c76dde613e838bbc67f8"}, + "telemetry": {:hex, :telemetry, "1.3.0", "fedebbae410d715cf8e7062c96a1ef32ec22e764197f70cda73d82778d61e7a2", [:rebar3], [], "hexpm", "7015fc8919dbe63764f4b4b87a95b7c0996bd539e0d499be6ec9d7f3875b79e6"}, + "unicode_util_compat": {:hex, :unicode_util_compat, "0.7.1", "a48703a25c170eedadca83b11e88985af08d35f37c6f664d6dcfb106a97782fc", [:rebar3], [], "hexpm", "b3a917854ce3ae233619744ad1e0102e05673136776fb2fa76234f3e03b23642"}, + "websock": {:hex, :websock, "0.5.3", "2f69a6ebe810328555b6fe5c831a851f485e303a7c8ce6c5f675abeb20ebdadc", [:mix], [], "hexpm", "6105453d7fac22c712ad66fab1d45abdf049868f253cf719b625151460b8b453"}, + "websock_adapter": {:hex, :websock_adapter, "0.5.9", "43dc3ba6d89ef5dec5b1d0a39698436a1e856d000d84bf31a3149862b01a287f", [:mix], [{:bandit, ">= 0.6.0", [hex: :bandit, repo: "hexpm", optional: true]}, {:plug, "~> 1.14", [hex: :plug, repo: "hexpm", optional: false]}, {:plug_cowboy, "~> 2.6", [hex: :plug_cowboy, repo: "hexpm", optional: true]}, {:websock, "~> 0.5", [hex: :websock, repo: "hexpm", optional: false]}], "hexpm", "5534d5c9adad3c18a0f58a9371220d75a803bf0b9a3d87e6fe072faaeed76a08"}, } diff --git a/test/scout_apm/commands/application_event_test.exs b/test/scout_apm/commands/application_event_test.exs new file mode 100644 index 0000000..749dace --- /dev/null +++ b/test/scout_apm/commands/application_event_test.exs @@ -0,0 +1,141 @@ +defmodule ScoutApm.Command.ApplicationEventTest do + use ExUnit.Case + + alias ScoutApm.Command.ApplicationEvent + + describe "app_metadata/0" do + test "returns an ApplicationEvent struct with scout.metadata event_type" do + result = ApplicationEvent.app_metadata() + + assert %ApplicationEvent{} = result + assert result.event_type == "scout.metadata" + assert is_map(result.event_value) + end + + test "includes language info" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + assert metadata.language == "elixir" + assert is_binary(metadata.language_version) + assert metadata.language_version =~ ~r/^\d+\.\d+\.\d+/ + assert metadata.language_version =~ "OTP" + assert metadata.language_version =~ "ERTS" + end + + test "includes version matching System.version()" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + assert metadata.version == System.version() + end + + test "includes server_time in ISO 8601 format" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + assert is_binary(metadata.server_time) + assert metadata.server_time =~ ~r/^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}/ + assert String.ends_with?(metadata.server_time, "Z") + end + + test "includes libraries as list of [name, version] pairs" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + assert is_list(metadata.libraries) + assert length(metadata.libraries) > 0 + + # Each library should be a [name, version] list + Enum.each(metadata.libraries, fn lib -> + assert is_list(lib) + assert length(lib) == 2 + [name, version] = lib + assert is_binary(name) + assert is_binary(version) + end) + + # Should include elixir itself + assert Enum.any?(metadata.libraries, fn [name, _] -> name == "elixir" end) + end + + test "includes application_root as current working directory" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + {:ok, cwd} = File.cwd() + assert metadata.application_root == cwd + end + + test "detects framework when loaded" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + # Framework detection should return a string (may be empty if no framework loaded) + assert is_binary(metadata.framework) + assert is_binary(metadata.framework_version) + + # If Phoenix is loaded, should detect it + if Application.loaded_applications() + |> Enum.any?(fn {name, _, _} -> name == :phoenix end) do + assert metadata.framework == "Phoenix" + assert metadata.framework_version =~ ~r/^\d+\.\d+/ + end + end + + test "detects app server when loaded" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + assert is_binary(metadata.app_server) + + # If Cowboy or Bandit is loaded, should detect it + loaded_apps = Application.loaded_applications() |> Enum.map(fn {name, _, _} -> name end) + + cond do + :bandit in loaded_apps -> assert metadata.app_server == "Bandit" + :cowboy in loaded_apps -> assert metadata.app_server == "Cowboy" + true -> assert metadata.app_server == "" + end + end + + test "detects database adapter when loaded" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + assert is_binary(metadata.database_adapter) + + # If a known adapter is loaded, should detect it + loaded_apps = Application.loaded_applications() |> Enum.map(fn {name, _, _} -> name end) + + cond do + :postgrex in loaded_apps -> + assert metadata.database_adapter == "PostgreSQL" + + :myxql in loaded_apps -> + assert metadata.database_adapter == "MySQL" + + :tds in loaded_apps -> + assert metadata.database_adapter == "MSSQL" + + :exqlite in loaded_apps or :ecto_sqlite3 in loaded_apps -> + assert metadata.database_adapter == "SQLite" + + true -> + assert metadata.database_adapter == "" + end + end + + test "includes hostname" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + assert is_binary(metadata.hostname) + end + + test "includes git_sha" do + %{event_value: metadata} = ApplicationEvent.app_metadata() + + # git_sha can be empty string if not in a git repo + assert is_binary(metadata.git_sha) + end + + test "includes source as process identifier" do + result = ApplicationEvent.app_metadata() + + assert is_binary(result.source) + assert result.source =~ ~r/#PID + error_data = ErrorData.from_exception(e, stacktrace: __STACKTRACE__) + assert length(error_data.trace) > 0 + assert Enum.any?(error_data.trace, &String.contains?(&1, "error_data_test.exs")) + end + end + + test "includes request path when provided" do + exception = %RuntimeError{message: "test"} + error_data = ErrorData.from_exception(exception, request_path: "/api/users") + + assert error_data.request_uri == "/api/users" + end + + test "filters request params" do + exception = %RuntimeError{message: "test"} + + error_data = + ErrorData.from_exception(exception, + request_params: %{"password" => "secret", "name" => "john"} + ) + + assert error_data.request_params["password"] == "[FILTERED]" + assert error_data.request_params["name"] == "john" + end + + test "includes custom controller" do + exception = %RuntimeError{message: "test"} + error_data = ErrorData.from_exception(exception, custom_controller: "UserController#show") + + assert error_data.request_components["controller"] == "UserController#show" + end + + test "includes user-provided context" do + exception = %RuntimeError{message: "test"} + error_data = ErrorData.from_exception(exception, context: %{user_id: 123}) + + assert error_data.context[:user_id] == 123 + end + + test "includes custom params" do + exception = %RuntimeError{message: "test"} + error_data = ErrorData.from_exception(exception, custom_params: %{extra: "data"}) + + assert error_data.context["custom_params"][:extra] == "data" + end + end + + describe "from_telemetry/4" do + test "handles :error kind with exception" do + exception = %ArgumentError{message: "invalid argument"} + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + error_data = ErrorData.from_telemetry(:error, exception, stacktrace, []) + + assert error_data.exception_class == "ArgumentError" + assert error_data.message == "invalid argument" + end + + test "handles :error kind with non-exception reason" do + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + error_data = ErrorData.from_telemetry(:error, {:badmatch, :something}, stacktrace, []) + + assert error_data.exception_class == "ErlangError" + assert error_data.message =~ "badmatch" + end + + test "handles :throw kind" do + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + error_data = ErrorData.from_telemetry(:throw, "thrown value", stacktrace, []) + + assert error_data.exception_class == "ThrowError" + assert error_data.message =~ "thrown value" + end + + test "handles :exit kind" do + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + error_data = ErrorData.from_telemetry(:exit, :normal, stacktrace, []) + + assert error_data.exception_class == "ExitError" + assert error_data.message =~ "normal" + end + + test "includes options" do + exception = %RuntimeError{message: "test"} + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + error_data = + ErrorData.from_telemetry(:error, exception, stacktrace, + request_path: "/test", + custom_controller: "TestController" + ) + + assert error_data.request_uri == "/test" + assert error_data.request_components["controller"] == "TestController" + end + end + + describe "to_map/1" do + test "converts error data to a map" do + exception = %RuntimeError{message: "test error"} + error_data = ErrorData.from_exception(exception, request_path: "/test") + + map = ErrorData.to_map(error_data) + + assert map["exception_class"] == "RuntimeError" + assert map["message"] == "test error" + assert map["request_uri"] == "/test" + assert is_list(map["trace"]) + end + + test "excludes nil values" do + exception = %RuntimeError{message: "test"} + error_data = ErrorData.from_exception(exception) + + map = ErrorData.to_map(error_data) + + # request_params should not be present if nil + refute Map.has_key?(map, "request_params") + refute Map.has_key?(map, "request_session") + refute Map.has_key?(map, "environment") + end + end +end diff --git a/test/scout_apm/error/error_service_test.exs b/test/scout_apm/error/error_service_test.exs new file mode 100644 index 0000000..422d195 --- /dev/null +++ b/test/scout_apm/error/error_service_test.exs @@ -0,0 +1,38 @@ +defmodule ScoutApm.Error.ErrorServiceTest do + use ExUnit.Case + + alias ScoutApm.Error.ErrorData + alias ScoutApm.Error.ErrorService + + # The ErrorService is started by the application, so we don't need to start it here + + describe "send/1" do + test "accepts error data and returns :ok" do + error_data = + ErrorData.from_exception(%RuntimeError{message: "test"}, stacktrace: []) + + assert ErrorService.send(error_data) == :ok + end + end + + describe "flush/0" do + test "forces immediate flush and returns :ok" do + assert ErrorService.flush() == :ok + end + end + + describe "drain/1" do + test "waits for queue to drain and returns :ok" do + # Send some errors + for i <- 1..3 do + error_data = + ErrorData.from_exception(%RuntimeError{message: "test #{i}"}, stacktrace: []) + + ErrorService.send(error_data) + end + + # Drain should complete + assert ErrorService.drain(5000) == :ok + end + end +end diff --git a/test/scout_apm/error/parameter_filter_test.exs b/test/scout_apm/error/parameter_filter_test.exs new file mode 100644 index 0000000..11a26cf --- /dev/null +++ b/test/scout_apm/error/parameter_filter_test.exs @@ -0,0 +1,112 @@ +defmodule ScoutApm.Error.ParameterFilterTest do + use ExUnit.Case + + alias ScoutApm.Error.ParameterFilter + + describe "filter/1" do + test "returns nil for nil input" do + assert ParameterFilter.filter(nil) == nil + end + + test "filters password keys" do + params = %{"password" => "secret123", "username" => "john"} + result = ParameterFilter.filter(params) + + assert result["password"] == "[FILTERED]" + assert result["username"] == "john" + end + + test "filters token keys" do + params = %{"token" => "abc123", "auth_token" => "xyz789", "data" => "value"} + result = ParameterFilter.filter(params) + + assert result["token"] == "[FILTERED]" + assert result["auth_token"] == "[FILTERED]" + assert result["data"] == "value" + end + + test "filters api_key and apikey" do + params = %{"api_key" => "key1", "apikey" => "key2", "public_id" => "123"} + result = ParameterFilter.filter(params) + + assert result["api_key"] == "[FILTERED]" + assert result["apikey"] == "[FILTERED]" + assert result["public_id"] == "123" + end + + test "filters secret and secret_key" do + params = %{"secret" => "shhh", "secret_key" => "very_secret"} + result = ParameterFilter.filter(params) + + assert result["secret"] == "[FILTERED]" + assert result["secret_key"] == "[FILTERED]" + end + + test "filters credit card related keys" do + params = %{"card[number]" => "4111111111111111", "name" => "John"} + result = ParameterFilter.filter(params) + + assert result["card[number]"] == "[FILTERED]" + assert result["name"] == "John" + end + + test "filters case-insensitively" do + params = %{"PASSWORD" => "secret", "Password" => "secret2", "pAssWoRd" => "secret3"} + result = ParameterFilter.filter(params) + + assert result["PASSWORD"] == "[FILTERED]" + assert result["Password"] == "[FILTERED]" + assert result["pAssWoRd"] == "[FILTERED]" + end + + test "filters nested maps" do + params = %{ + "user" => %{ + "email" => "test@example.com", + "password" => "secret" + }, + "public" => "data" + } + + result = ParameterFilter.filter(params) + + assert result["user"]["email"] == "test@example.com" + assert result["user"]["password"] == "[FILTERED]" + assert result["public"] == "data" + end + + test "filters lists" do + params = [%{"password" => "secret"}, %{"name" => "john"}] + result = ParameterFilter.filter(params) + + assert Enum.at(result, 0)["password"] == "[FILTERED]" + assert Enum.at(result, 1)["name"] == "john" + end + + test "handles atom keys" do + params = %{password: "secret", username: "john"} + result = ParameterFilter.filter(params) + + assert result[:password] == "[FILTERED]" + assert result[:username] == "john" + end + + test "preserves non-sensitive data types" do + params = %{ + "string" => "hello", + "number" => 42, + "float" => 3.14, + "boolean" => true, + "atom" => :value + } + + result = ParameterFilter.filter(params) + + assert result["string"] == "hello" + assert result["number"] == 42 + assert result["float"] == 3.14 + assert result["boolean"] == true + assert result["atom"] == "value" + end + end +end diff --git a/test/scout_apm/error_test.exs b/test/scout_apm/error_test.exs new file mode 100644 index 0000000..9b71b75 --- /dev/null +++ b/test/scout_apm/error_test.exs @@ -0,0 +1,102 @@ +defmodule ScoutApm.ErrorTest do + use ExUnit.Case + + describe "capture/2" do + test "captures an exception and returns :ok" do + exception = %RuntimeError{message: "test error"} + + assert ScoutApm.Error.capture(exception) == :ok + end + + test "captures with stacktrace" do + try do + raise RuntimeError, "test" + rescue + e -> + assert ScoutApm.Error.capture(e, stacktrace: __STACKTRACE__) == :ok + end + end + + test "captures with additional context" do + exception = %RuntimeError{message: "test"} + + result = + ScoutApm.Error.capture(exception, + context: %{user_id: 123}, + request_path: "/api/users", + request_params: %{"action" => "create"} + ) + + assert result == :ok + end + + test "captures with custom controller" do + exception = %RuntimeError{message: "test"} + + result = + ScoutApm.Error.capture(exception, + custom_controller: "UserController#show" + ) + + assert result == :ok + end + + test "captures with custom params" do + exception = %RuntimeError{message: "test"} + + result = + ScoutApm.Error.capture(exception, + custom_params: %{extra: "data"} + ) + + assert result == :ok + end + end + + describe "capture_from_telemetry/4" do + test "captures error kind with exception" do + exception = %ArgumentError{message: "bad arg"} + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + assert ScoutApm.Error.capture_from_telemetry(:error, exception, stacktrace) == :ok + end + + test "captures error kind with non-exception" do + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + assert ScoutApm.Error.capture_from_telemetry(:error, :badarg, stacktrace) == :ok + end + + test "captures throw kind" do + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + assert ScoutApm.Error.capture_from_telemetry(:throw, "thrown", stacktrace) == :ok + end + + test "captures exit kind" do + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + assert ScoutApm.Error.capture_from_telemetry(:exit, :normal, stacktrace) == :ok + end + + test "captures with options" do + exception = %RuntimeError{message: "test"} + stacktrace = [{__MODULE__, :test, 0, [file: ~c"test.ex", line: 1]}] + + result = + ScoutApm.Error.capture_from_telemetry(:error, exception, stacktrace, + request_path: "/test", + custom_controller: "TestController" + ) + + assert result == :ok + end + end + + describe "enabled?/0" do + test "returns true when errors are enabled" do + # Default config has errors_enabled: true + assert ScoutApm.Error.enabled?() == true + end + end +end diff --git a/test/scout_apm/instruments/ecto_logger_test.exs b/test/scout_apm/instruments/ecto_logger_test.exs index 658cc47..c8942ff 100644 --- a/test/scout_apm/instruments/ecto_logger_test.exs +++ b/test/scout_apm/instruments/ecto_logger_test.exs @@ -40,6 +40,36 @@ defmodule ScoutApm.Instruments.EctoLoggerTest do Map.get(tag, :tag) == "db.statement" end) end + + test "includes db.rows_returned and db.operation tags when result is available" do + value = %{ + decode_time: 16000, + query_time: 1_192_999, + queue_time: 36000 + } + + metadata = %{ + source: "users", + query: "SELECT u0.\"id\", u0.\"name\", u0.\"age\" FROM \"users\" AS u0", + result: {:ok, %{command: :select, num_rows: 5}} + } + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + ScoutApm.Instruments.EctoLogger.record(value, metadata) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "db.rows_returned" && Map.get(tag, :value) == "5" + end) + + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "db.operation" && Map.get(tag, :value) == "Select" + end) + end end describe "log/1" do @@ -74,5 +104,81 @@ defmodule ScoutApm.Instruments.EctoLoggerTest do Map.get(tag, :tag) == "db.statement" end) end + + test "includes db.rows_returned and db.operation tags" do + entry = %{ + decode_time: 16000, + query_time: 1_192_999, + queue_time: 36000, + result: {:ok, %{command: :insert, num_rows: 1}}, + source: "users", + query: "INSERT INTO \"users\" (\"name\") VALUES ($1)" + } + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + ScoutApm.Instruments.EctoLogger.log(entry) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "db.rows_returned" && Map.get(tag, :value) == "1" + end) + + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "db.operation" && Map.get(tag, :value) == "Insert" + end) + end + end + + describe "extract_result_info/1" do + alias ScoutApm.Instruments.EctoLogger + + test "extracts command and num_rows from successful result" do + metadata = %{result: {:ok, %{command: :select, num_rows: 10}}} + assert {"Select", 10} = EctoLogger.extract_result_info(metadata) + end + + test "normalizes insert command" do + metadata = %{result: {:ok, %{command: :insert, num_rows: 1}}} + assert {"Insert", 1} = EctoLogger.extract_result_info(metadata) + end + + test "normalizes update command" do + metadata = %{result: {:ok, %{command: :update, num_rows: 3}}} + assert {"Update", 3} = EctoLogger.extract_result_info(metadata) + end + + test "normalizes delete command" do + metadata = %{result: {:ok, %{command: :delete, num_rows: 2}}} + assert {"Delete", 2} = EctoLogger.extract_result_info(metadata) + end + + test "handles unknown commands by capitalizing" do + metadata = %{result: {:ok, %{command: :truncate, num_rows: 0}}} + assert {"Truncate", 0} = EctoLogger.extract_result_info(metadata) + end + + test "returns nil tuple when result is error" do + metadata = %{result: {:error, :some_error}} + assert {nil, nil} = EctoLogger.extract_result_info(metadata) + end + + test "returns nil tuple when result is not present" do + metadata = %{source: "users"} + assert {nil, nil} = EctoLogger.extract_result_info(metadata) + end + + test "handles result without num_rows" do + metadata = %{result: {:ok, %{command: :select}}} + assert {"Select", nil} = EctoLogger.extract_result_info(metadata) + end + + test "handles result without command" do + metadata = %{result: {:ok, %{num_rows: 5}}} + assert {nil, 5} = EctoLogger.extract_result_info(metadata) + end end end diff --git a/test/scout_apm/instruments/eex_engine_test.exs b/test/scout_apm/instruments/eex_engine_test.exs index c39f108..016f562 100644 --- a/test/scout_apm/instruments/eex_engine_test.exs +++ b/test/scout_apm/instruments/eex_engine_test.exs @@ -1,30 +1,21 @@ defmodule ScoutApm.Instruments.EExEngineTest do use ExUnit.Case - defmodule EExView do - use Phoenix.Template, - root: "./test/support/templates", - template_engines: %{ - eex: ScoutApm.Instruments.EExEngine - } - - def render(template, assigns) do - render_template(template, assigns) - end - end - describe "compile/2" do - test "can compile" do - ScoutApm.Instruments.EExEngine.compile( - "./test/support/templates/simple.html.eex", - "simple.html" - ) - end - end + test "can compile EEx templates" do + result = + ScoutApm.Instruments.EExEngine.compile( + "./test/support/templates/simple.html.eex", + "simple.html" + ) + + # Verify it returns quoted code (AST) + assert is_tuple(result) - describe "render/2" do - test "can render" do - assert EExView.render("test/support/templates/simple.html", %{}) + # Verify it includes our timing instrumentation + result_string = Macro.to_string(result) + assert result_string =~ "ScoutApm.Tracing.timing" + assert result_string =~ "EEx" end end end diff --git a/test/scout_apm/instruments/exs_engine_test.exs b/test/scout_apm/instruments/exs_engine_test.exs index 636ab03..8e2b5a1 100644 --- a/test/scout_apm/instruments/exs_engine_test.exs +++ b/test/scout_apm/instruments/exs_engine_test.exs @@ -1,30 +1,21 @@ defmodule ScoutApm.Instruments.ExsEngineTest do use ExUnit.Case - defmodule ExsView do - use Phoenix.Template, - root: "./test/support/templates", - template_engines: %{ - exs: ScoutApm.Instruments.ExsEngine - } - - def render(template, assigns) do - render_template(template, assigns) - end - end - describe "compile/2" do - test "can compile" do - ScoutApm.Instruments.ExsEngine.compile( - "./test/support/templates/simple.json.exs", - "simple.json" - ) - end - end + test "can compile ExS templates" do + result = + ScoutApm.Instruments.ExsEngine.compile( + "./test/support/templates/simple.json.exs", + "simple.json" + ) + + # Verify it returns quoted code (AST) + assert is_tuple(result) - describe "render/2" do - test "can render" do - assert ExsView.render("test/support/templates/simple.json", %{}) + # Verify it includes our timing instrumentation + result_string = Macro.to_string(result) + assert result_string =~ "ScoutApm.Tracing.timing" + assert result_string =~ "Exs" end end end diff --git a/test/scout_apm/instruments/finch_telemetry_test.exs b/test/scout_apm/instruments/finch_telemetry_test.exs new file mode 100644 index 0000000..9c4a2fd --- /dev/null +++ b/test/scout_apm/instruments/finch_telemetry_test.exs @@ -0,0 +1,274 @@ +defmodule ScoutApm.Instruments.FinchTelemetryTest do + use ExUnit.Case + + alias ScoutApm.Instruments.FinchTelemetry + + setup do + ScoutApm.TestCollector.clear_messages() + :ok + end + + describe "attach/0" do + test "attaches telemetry handlers successfully" do + # Detach first in case already attached + try do + FinchTelemetry.detach() + rescue + _ -> :ok + end + + assert :ok = FinchTelemetry.attach() + + # Clean up + FinchTelemetry.detach() + end + end + + describe "handle_event/4 for request stop" do + test "records HTTP layer for successful request" do + request = %{ + scheme: :https, + host: "api.example.com", + port: 443, + path: "/users", + method: "GET" + } + + # 1ms in native time + measurements = %{duration: 1_000_000} + metadata = %{request: request, result: {:ok, %{status: 200}}} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + FinchTelemetry.handle_event([:finch, :request, :stop], measurements, metadata, nil) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + # Verify HTTP operation span was created + assert Enum.any?(commands, fn command -> + span = Map.get(command, :StartSpan) + span && Map.get(span, :operation) == "HTTP/GET" + end) + + # Verify "url" tag for core agent domain extraction + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + + tag && Map.get(tag, :tag) == "url" && + Map.get(tag, :value) == "https://api.example.com/users" + end) + + # Verify "http.url" tag for compatibility + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + + tag && Map.get(tag, :tag) == "http.url" && + Map.get(tag, :value) == "https://api.example.com/users" + end) + + # Verify http.status_code tag was created + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.status_code" && Map.get(tag, :value) == "200" + end) + end + + test "records HTTP layer with POST method" do + request = %{ + scheme: :https, + host: "api.example.com", + port: 443, + path: "/users", + method: :post + } + + measurements = %{duration: 2_000_000} + metadata = %{request: request, result: {:ok, %{status: 201}}} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + FinchTelemetry.handle_event([:finch, :request, :stop], measurements, metadata, nil) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + assert Enum.any?(commands, fn command -> + span = Map.get(command, :StartSpan) + span && Map.get(span, :operation) == "HTTP/POST" + end) + + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.status_code" && Map.get(tag, :value) == "201" + end) + end + + test "omits default ports in URL" do + request_https = %{ + scheme: :https, + host: "api.example.com", + port: 443, + path: "/test", + method: "GET" + } + + request_http = %{ + scheme: :http, + host: "api.example.com", + port: 80, + path: "/test", + method: "GET" + } + + request_custom = %{ + scheme: :https, + host: "api.example.com", + port: 8443, + path: "/test", + method: "GET" + } + + measurements = %{duration: 1_000_000} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + + FinchTelemetry.handle_event( + [:finch, :request, :stop], + measurements, + %{request: request_https, result: {:ok, %{status: 200}}}, + nil + ) + + FinchTelemetry.handle_event( + [:finch, :request, :stop], + measurements, + %{request: request_http, result: {:ok, %{status: 200}}}, + nil + ) + + FinchTelemetry.handle_event( + [:finch, :request, :stop], + measurements, + %{request: request_custom, result: {:ok, %{status: 200}}}, + nil + ) + + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + tag_values = fn tag_name -> + commands + |> Enum.filter(fn cmd -> Map.has_key?(cmd, :TagSpan) end) + |> Enum.map(fn %{TagSpan: tag} -> tag end) + |> Enum.filter(fn tag -> tag.tag == tag_name end) + |> Enum.map(fn tag -> tag.value end) + end + + # Both "url" and "http.url" tags should have the same values + for tag_name <- ["url", "http.url"] do + urls = tag_values.(tag_name) + assert "https://api.example.com/test" in urls + assert "http://api.example.com/test" in urls + assert "https://api.example.com:8443/test" in urls + end + end + + test "skips Scout APM hosts" do + scout_hosts = [ + %{ + scheme: :https, + host: "errors.scoutapm.com", + port: 443, + path: "/errors", + method: "POST" + }, + %{scheme: :https, host: "apm.scoutapp.com", port: 443, path: "/checkin", method: "POST"}, + %{scheme: :https, host: "checkin.scoutapm.com", port: 443, path: "/", method: "POST"}, + %{ + scheme: :https, + host: "otlp.scoutotel.com", + port: 4318, + path: "/v1/logs", + method: "POST" + } + ] + + measurements = %{duration: 1_000_000} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + + for request <- scout_hosts do + FinchTelemetry.handle_event( + [:finch, :request, :stop], + measurements, + %{request: request, result: {:ok, %{status: 200}}}, + nil + ) + end + + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + # Should only have the Controller span, no HTTP spans for Scout hosts + http_spans = + Enum.filter(commands, fn cmd -> + case Map.get(cmd, :StartSpan) do + %{operation: "HTTP/" <> _} -> true + _ -> false + end + end) + + assert Enum.empty?(http_spans) + end + end + + describe "handle_event/4 for request exception" do + test "records HTTP layer for failed request" do + request = %{ + scheme: :https, + host: "api.example.com", + port: 443, + path: "/users", + method: "GET" + } + + measurements = %{duration: 5_000_000} + + metadata = %{ + request: request, + kind: :error, + reason: %RuntimeError{message: "Connection refused"} + } + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + FinchTelemetry.handle_event([:finch, :request, :exception], measurements, metadata, nil) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + # Verify HTTP operation span was created + assert Enum.any?(commands, fn command -> + span = Map.get(command, :StartSpan) + span && Map.get(span, :operation) == "HTTP/GET" + end) + + # Verify both url tags were created + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "url" + end) + + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.url" + end) + + # No status code tag for exceptions + refute Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.status_code" + end) + end + end +end diff --git a/test/scout_apm/instruments/heex_engine_test.exs b/test/scout_apm/instruments/heex_engine_test.exs new file mode 100644 index 0000000..d834680 --- /dev/null +++ b/test/scout_apm/instruments/heex_engine_test.exs @@ -0,0 +1,41 @@ +if Code.ensure_loaded?(Phoenix.LiveView.HTMLEngine) do + defmodule ScoutApm.Instruments.HEExEngineTest do + use ExUnit.Case + + describe "compile/2" do + test "can compile HEEx templates" do + result = + ScoutApm.Instruments.HEExEngine.compile( + "./test/support/templates/simple.html.heex", + "simple.html" + ) + + # Verify it returns quoted code (AST) + assert is_tuple(result) + + # Verify it includes our timing instrumentation + result_string = Macro.to_string(result) + assert result_string =~ "ScoutApm.Tracing.timing" + assert result_string =~ "HEEx" + end + + test "marks layout templates as non-scopable" do + # Create a temporary layout template for testing + layout_path = "./test/support/templates/layout/app.html.heex" + File.mkdir_p!("./test/support/templates/layout") + File.write!(layout_path, "<%= @inner_content %>") + + result = + ScoutApm.Instruments.HEExEngine.compile(layout_path, "app.html") + + result_string = Macro.to_string(result) + # Layout should have scopable: !true (which evaluates to false at runtime) + assert result_string =~ "scopable: !true" + + # Clean up + File.rm!(layout_path) + File.rmdir!("./test/support/templates/layout") + end + end + end +end diff --git a/test/scout_apm/instruments/tesla_telemetry_test.exs b/test/scout_apm/instruments/tesla_telemetry_test.exs new file mode 100644 index 0000000..e489d4a --- /dev/null +++ b/test/scout_apm/instruments/tesla_telemetry_test.exs @@ -0,0 +1,275 @@ +defmodule ScoutApm.Instruments.TeslaTelemetryTest do + use ExUnit.Case + + alias ScoutApm.Instruments.TeslaTelemetry + + setup do + ScoutApm.TestCollector.clear_messages() + :ok + end + + describe "attach/0" do + test "attaches telemetry handlers successfully" do + # Detach first in case already attached + try do + TeslaTelemetry.detach() + rescue + _ -> :ok + end + + assert :ok = TeslaTelemetry.attach() + + # Clean up + TeslaTelemetry.detach() + end + end + + describe "handle_event/4 for request stop" do + test "records HTTP layer for successful request" do + env = %{ + url: "https://api.example.com/users", + method: :get, + status: 200 + } + + # 1ms in native time + measurements = %{duration: 1_000_000} + metadata = %{env: env} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + TeslaTelemetry.handle_event([:tesla, :request, :stop], measurements, metadata, nil) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + # Verify HTTP operation span was created + assert Enum.any?(commands, fn command -> + span = Map.get(command, :StartSpan) + span && Map.get(span, :operation) == "HTTP/GET" + end) + + # Verify "url" tag for core agent domain extraction + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + + tag && Map.get(tag, :tag) == "url" && + Map.get(tag, :value) == "https://api.example.com/users" + end) + + # Verify "http.url" tag for compatibility + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + + tag && Map.get(tag, :tag) == "http.url" && + Map.get(tag, :value) == "https://api.example.com/users" + end) + + # Verify http.status_code tag was created + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.status_code" && Map.get(tag, :value) == "200" + end) + end + + test "records HTTP layer with POST method" do + env = %{ + url: "https://api.example.com/users", + method: :post, + status: 201 + } + + measurements = %{duration: 2_000_000} + metadata = %{env: env} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + TeslaTelemetry.handle_event([:tesla, :request, :stop], measurements, metadata, nil) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + assert Enum.any?(commands, fn command -> + span = Map.get(command, :StartSpan) + span && Map.get(span, :operation) == "HTTP/POST" + end) + + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.status_code" && Map.get(tag, :value) == "201" + end) + end + + test "handles string method values" do + env = %{ + url: "https://api.example.com/users", + method: "PUT", + status: 200 + } + + measurements = %{duration: 1_000_000} + metadata = %{env: env} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + TeslaTelemetry.handle_event([:tesla, :request, :stop], measurements, metadata, nil) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + assert Enum.any?(commands, fn command -> + span = Map.get(command, :StartSpan) + span && Map.get(span, :operation) == "HTTP/PUT" + end) + end + + test "strips query strings from URLs" do + env = %{ + url: "https://api.example.com/users?api_key=secret123&page=1", + method: :get, + status: 200 + } + + measurements = %{duration: 1_000_000} + metadata = %{env: env} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + TeslaTelemetry.handle_event([:tesla, :request, :stop], measurements, metadata, nil) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + # URL should have query string stripped + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + + tag && Map.get(tag, :tag) == "url" && + Map.get(tag, :value) == "https://api.example.com/users" + end) + + # Should NOT contain query parameters + refute Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + + tag && Map.get(tag, :tag) == "url" && + String.contains?(Map.get(tag, :value, ""), "secret123") + end) + end + + test "skips Scout APM hosts" do + scout_envs = [ + %{url: "https://errors.scoutapm.com/errors", method: :post, status: 200}, + %{url: "https://apm.scoutapp.com/checkin", method: :post, status: 200}, + %{url: "https://checkin.scoutapm.com/", method: :post, status: 200}, + %{url: "https://otlp.scoutotel.com:4318/v1/logs", method: :post, status: 200} + ] + + measurements = %{duration: 1_000_000} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + + for env <- scout_envs do + TeslaTelemetry.handle_event([:tesla, :request, :stop], measurements, %{env: env}, nil) + end + + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + # Should only have the Controller span, no HTTP spans for Scout hosts + http_spans = + Enum.filter(commands, fn cmd -> + case Map.get(cmd, :StartSpan) do + %{operation: "HTTP/" <> _} -> true + _ -> false + end + end) + + assert Enum.empty?(http_spans) + end + + test "handles request with error in metadata" do + env = %{ + url: "https://api.example.com/users", + method: :get, + status: nil + } + + measurements = %{duration: 5_000_000} + metadata = %{env: env, error: {:error, :econnrefused}} + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + TeslaTelemetry.handle_event([:tesla, :request, :stop], measurements, metadata, nil) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + # Verify HTTP operation span was created + assert Enum.any?(commands, fn command -> + span = Map.get(command, :StartSpan) + span && Map.get(span, :operation) == "HTTP/GET" + end) + + # Verify both url tags were created + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "url" + end) + + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.url" + end) + + # No status code tag for errors + refute Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.status_code" + end) + end + end + + describe "handle_event/4 for request exception" do + test "records HTTP layer for failed request" do + env = %{ + url: "https://api.example.com/users", + method: :get + } + + measurements = %{duration: 5_000_000} + + metadata = %{ + env: env, + kind: :error, + reason: %RuntimeError{message: "Connection refused"}, + stacktrace: [] + } + + ScoutApm.TrackedRequest.start_layer("Controller", "test") + TeslaTelemetry.handle_event([:tesla, :request, :exception], measurements, metadata, nil) + ScoutApm.TrackedRequest.stop_layer() + + [%{BatchCommand: %{commands: commands}}] = ScoutApm.TestCollector.messages() + + # Verify HTTP operation span was created + assert Enum.any?(commands, fn command -> + span = Map.get(command, :StartSpan) + span && Map.get(span, :operation) == "HTTP/GET" + end) + + # Verify both url tags were created + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "url" + end) + + assert Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.url" + end) + + # No status code tag for exceptions + refute Enum.any?(commands, fn command -> + tag = Map.get(command, :TagSpan) + tag && Map.get(tag, :tag) == "http.status_code" + end) + end + end +end diff --git a/test/scout_apm/logging/context_extractor_test.exs b/test/scout_apm/logging/context_extractor_test.exs new file mode 100644 index 0000000..0d58ad2 --- /dev/null +++ b/test/scout_apm/logging/context_extractor_test.exs @@ -0,0 +1,343 @@ +defmodule ScoutApm.Logging.ContextExtractorTest do + use ExUnit.Case + + alias ScoutApm.Logging.ContextExtractor + alias ScoutApm.TrackedRequest + alias ScoutApm.Internal.Context + + defp find_attr(context, key) do + Enum.find_value(context, fn + {^key, v} -> v + _ -> nil + end) + end + + defp has_attr?(context, key) do + Enum.any?(context, fn {k, _v} -> k == key end) + end + + defp make_tr(overrides \\ %{}) do + defaults = %{ + id: "test-123", + root_layer: nil, + layers: [], + children: [], + contexts: [], + collector_fn: nil, + error: false, + ignored: false, + ignoring_depth: 0 + } + + struct(TrackedRequest, Map.merge(defaults, overrides)) + end + + defp make_layer(type, name, opts \\ %{}) do + defaults = %{ + type: type, + name: name, + started_at: ~N[2026-03-06 12:00:00.000000], + children: [] + } + + struct(ScoutApm.Internal.Layer, Map.merge(defaults, opts)) + end + + describe "extract/0" do + test "returns empty context when no tracked request" do + Process.delete(:scout_apm_request) + context = ContextExtractor.extract() + assert is_list(context) + end + + test "extracts context from tracked request" do + tr = + make_tr(%{ + id: "test-request-123", + root_layer: make_layer("Controller", "UsersController#show") + }) + + Process.put(:scout_apm_request, tr) + + try do + context = ContextExtractor.extract() + assert find_attr(context, "scout_transaction_id") == "test-request-123" + after + Process.delete(:scout_apm_request) + end + end + end + + describe "scout_transaction_id" do + test "uses scout_transaction_id naming (matching Python/Ruby)" do + context = ContextExtractor.extract_from_tracked_request(make_tr(%{id: "req-abc"})) + assert find_attr(context, "scout_transaction_id") == "req-abc" + refute has_attr?(context, "scout.request_id") + end + end + + describe "timing attributes" do + test "includes scout_start_time from root layer" do + tr = + make_tr(%{ + root_layer: + make_layer("Controller", "Test", %{started_at: ~N[2026-03-06 12:00:00.000000]}) + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "scout_start_time") == "2026-03-06T12:00:00.000000Z" + end + + test "includes scout_end_time and scout_duration when root layer is stopped" do + tr = + make_tr(%{ + root_layer: + make_layer("Controller", "Test", %{ + started_at: ~N[2026-03-06 12:00:00.000000], + stopped_at: ~N[2026-03-06 12:00:01.500000] + }) + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "scout_end_time") == "2026-03-06T12:00:01.500000Z" + assert find_attr(context, "scout_duration") == 1.5 + end + + test "omits end_time and duration when root layer not stopped" do + tr = make_tr(%{root_layer: make_layer("Controller", "Test")}) + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "scout_start_time") != nil + refute has_attr?(context, "scout_end_time") + refute has_attr?(context, "scout_duration") + end + + test "omits timing when no root layer" do + context = ContextExtractor.extract_from_tracked_request(make_tr()) + refute has_attr?(context, "scout_start_time") + end + end + + describe "scout_current_operation" do + test "includes current operation from active layer stack" do + tr = + make_tr(%{ + layers: [make_layer("Ecto", "MyApp.Repo")] + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "scout_current_operation") == "Ecto/MyApp.Repo" + end + + test "omits current operation when no active layers" do + context = ContextExtractor.extract_from_tracked_request(make_tr()) + refute has_attr?(context, "scout_current_operation") + end + end + + describe "entrypoint attributes" do + test "adds controller_entrypoint from active layer" do + tr = make_tr(%{layers: [make_layer("Controller", "UsersController#show")]}) + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "controller_entrypoint") == "UsersController#show" + end + + test "adds job_entrypoint for Job layers" do + tr = make_tr(%{layers: [make_layer("Job", "MyApp.Workers.EmailWorker")]}) + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "job_entrypoint") == "MyApp.Workers.EmailWorker" + end + + test "adds custom_entrypoint for other layer types" do + tr = make_tr(%{layers: [make_layer("Template", "index.html")]}) + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "custom_entrypoint") == "index.html" + end + + test "falls back to root_layer when layers stack is empty" do + tr = make_tr(%{root_layer: make_layer("Controller", "UsersController#index")}) + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "controller_entrypoint") == "UsersController#index" + end + + test "prefers root_layer Controller/Job over active non-Controller layer" do + tr = + make_tr(%{ + root_layer: make_layer("Controller", "UsersController#show"), + layers: [make_layer("Ecto", "MyApp.Repo")] + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "controller_entrypoint") == "UsersController#show" + refute has_attr?(context, "custom_entrypoint") + end + + test "finds Job entrypoint from layers stack when nested inside Step" do + # Simulates: Job started, then Step started (Step is current, Job is parent) + # layers stack is LIFO: [current_step, parent_job] + tr = + make_tr(%{ + root_layer: nil, + layers: [ + make_layer("Step", "PrintToConsole/log_result"), + make_layer("Job", "MyApp.Workers.EmailWorker") + ] + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "job_entrypoint") == "MyApp.Workers.EmailWorker" + assert find_attr(context, "scout_current_operation") == "Step/PrintToConsole/log_result" + refute has_attr?(context, "custom_entrypoint") + end + + test "finds Controller entrypoint from layers stack when nested inside Ecto" do + tr = + make_tr(%{ + root_layer: nil, + layers: [ + make_layer("Ecto", "MyApp.Repo"), + make_layer("Controller", "UsersController#show") + ] + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "controller_entrypoint") == "UsersController#show" + refute has_attr?(context, "custom_entrypoint") + end + + test "no entrypoint when no layers and no root_layer" do + context = ContextExtractor.extract_from_tracked_request(make_tr()) + + refute has_attr?(context, "controller_entrypoint") + refute has_attr?(context, "job_entrypoint") + refute has_attr?(context, "custom_entrypoint") + end + end + + describe "custom context - tags" do + test "uses scout_tag_{key} naming (matching Python)" do + tr = + make_tr(%{ + contexts: [%Context{type: :extra, key: "feature", value: "checkout"}] + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "scout_tag_feature") == "checkout" + refute has_attr?(context, "scout.tag.feature") + end + end + + describe "custom context - user" do + test "uses user.{key} naming (matching Ruby)" do + tr = + make_tr(%{ + contexts: [%Context{type: :user, key: "id", value: "user-456"}] + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + assert find_attr(context, "user.id") == "user-456" + refute has_attr?(context, "scout.user.id") + end + + test "excludes user ip (matching Ruby, atom key)" do + tr = + make_tr(%{ + contexts: [ + %Context{type: :user, key: :ip, value: "127.0.0.1"}, + %Context{type: :user, key: "id", value: "user-456"} + ] + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + refute has_attr?(context, "user.ip") + assert find_attr(context, "user.id") == "user-456" + end + + test "excludes user ip (matching Ruby)" do + tr = + make_tr(%{ + contexts: [ + %Context{type: :user, key: "ip", value: "127.0.0.1"}, + %Context{type: :user, key: "id", value: "user-456"} + ] + }) + + context = ContextExtractor.extract_from_tracked_request(tr) + refute has_attr?(context, "user.ip") + assert find_attr(context, "user.id") == "user-456" + end + end + + describe "Logger metadata fallback" do + test "stash_context stores entrypoint and transaction_id in Logger metadata" do + # Create a TrackedRequest so stash_context can read the id + tr = make_tr(%{id: "req-xyz"}) + Process.put(:scout_apm_request, tr) + + ContextExtractor.stash_context("Controller", "UsersController#show") + + assert Logger.metadata()[:scout_entrypoint_key] == "controller_entrypoint" + assert Logger.metadata()[:scout_entrypoint_name] == "UsersController#show" + assert Logger.metadata()[:scout_transaction_id] == "req-xyz" + after + Process.delete(:scout_apm_request) + + Logger.metadata( + scout_entrypoint_key: nil, + scout_entrypoint_name: nil, + scout_transaction_id: nil + ) + end + + test "extract/0 uses Logger metadata when no TrackedRequest exists" do + # Simulate: TrackedRequest existed when stash was called, now it's gone + tr = make_tr(%{id: "req-abc"}) + Process.put(:scout_apm_request, tr) + ContextExtractor.stash_context("Controller", "MessageController#create") + Process.delete(:scout_apm_request) + + context = ContextExtractor.extract() + assert find_attr(context, "controller_entrypoint") == "MessageController#create" + assert find_attr(context, "scout_transaction_id") == "req-abc" + after + Logger.metadata( + scout_entrypoint_key: nil, + scout_entrypoint_name: nil, + scout_transaction_id: nil + ) + end + + test "extract/0 uses Logger metadata for Job entrypoint" do + Process.delete(:scout_apm_request) + ContextExtractor.stash_context("Job", "Job/EmailWorker") + + context = ContextExtractor.extract() + assert find_attr(context, "job_entrypoint") == "Job/EmailWorker" + after + Logger.metadata( + scout_entrypoint_key: nil, + scout_entrypoint_name: nil, + scout_transaction_id: nil + ) + end + + test "TrackedRequest takes priority over Logger metadata" do + ContextExtractor.stash_context("Controller", "OldController#action") + + tr = make_tr(%{layers: [make_layer("Controller", "NewController#action")]}) + Process.put(:scout_apm_request, tr) + + try do + context = ContextExtractor.extract() + assert find_attr(context, "controller_entrypoint") == "NewController#action" + after + Process.delete(:scout_apm_request) + + Logger.metadata( + scout_entrypoint_key: nil, + scout_entrypoint_name: nil, + scout_transaction_id: nil + ) + end + end + end +end diff --git a/test/scout_apm/logging/log_record_test.exs b/test/scout_apm/logging/log_record_test.exs new file mode 100644 index 0000000..ae0bffa --- /dev/null +++ b/test/scout_apm/logging/log_record_test.exs @@ -0,0 +1,148 @@ +defmodule ScoutApm.Logging.LogRecordTest do + use ExUnit.Case + + alias ScoutApm.Logging.LogRecord + + describe "new/3" do + test "creates a log record with severity and message" do + record = LogRecord.new(:info, "Test message") + + assert record.severity == :info + assert record.message == "Test message" + assert is_integer(record.timestamp_nanos) + assert is_integer(record.observed_timestamp_nanos) + end + + test "creates a log record with attributes" do + record = LogRecord.new(:warning, "Warning", %{"key" => "value"}) + + assert record.attributes == %{"key" => "value"} + end + + test "truncates long messages" do + long_message = String.duplicate("a", 40_000) + record = LogRecord.new(:info, long_message) + + assert String.length(record.message) <= 32_768 + assert String.ends_with?(record.message, "...") + end + end + + describe "from_logger_event/2" do + test "creates from string message event" do + event = %{ + level: :info, + msg: {:string, "Hello world"}, + meta: %{ + time: System.system_time(:microsecond), + file: ~c"test.ex", + line: 10 + } + } + + record = LogRecord.from_logger_event(event) + + assert record.severity == :info + assert record.message == "Hello world" + end + + test "creates from binary string message" do + event = %{ + level: :error, + msg: {:string, "Binary message"}, + meta: %{time: System.system_time(:microsecond)} + } + + record = LogRecord.from_logger_event(event) + + assert record.message == "Binary message" + end + + test "creates from format message" do + event = %{ + level: :debug, + msg: {~c"User ~p logged in", [:john]}, + meta: %{time: System.system_time(:microsecond)} + } + + record = LogRecord.from_logger_event(event) + + assert record.message == "User john logged in" + end + + test "includes source location in attributes" do + event = %{ + level: :info, + msg: {:string, "test"}, + meta: %{ + time: System.system_time(:microsecond), + file: ~c"lib/my_app.ex", + line: 42, + mfa: {MyApp.Module, :function, 2} + } + } + + record = LogRecord.from_logger_event(event) + + assert record.attributes["code.filepath"] == "lib/my_app.ex" + assert record.attributes["code.lineno"] == 42 + assert record.attributes["code.function"] == "MyApp.Module.function/2" + end + + test "includes scout context" do + event = %{ + level: :info, + msg: {:string, "test"}, + meta: %{time: System.system_time(:microsecond)} + } + + scout_context = [ + {"scout.request_id", "req-123"}, + {"scout.transaction_name", "Controller/Users#show"} + ] + + record = LogRecord.from_logger_event(event, scout_context) + + assert record.attributes["scout.request_id"] == "req-123" + assert record.attributes["scout.transaction_name"] == "Controller/Users#show" + end + + test "includes custom metadata" do + event = %{ + level: :info, + msg: {:string, "test"}, + meta: %{ + time: System.system_time(:microsecond), + user_id: 123, + request_id: "abc" + } + } + + record = LogRecord.from_logger_event(event) + + assert record.attributes["user_id"] == 123 + assert record.attributes["request_id"] == "abc" + end + + test "filters internal metadata" do + event = %{ + level: :info, + msg: {:string, "test"}, + meta: %{ + time: System.system_time(:microsecond), + gl: self(), + pid: self(), + domain: [:elixir], + custom_key: "value" + } + } + + record = LogRecord.from_logger_event(event) + + refute Map.has_key?(record.attributes, "gl") + refute Map.has_key?(record.attributes, "pid") + refute Map.has_key?(record.attributes, "domain") + assert record.attributes["custom_key"] == "value" + end + end +end diff --git a/test/scout_apm/logging/otlp/encoder_test.exs b/test/scout_apm/logging/otlp/encoder_test.exs new file mode 100644 index 0000000..f75bc4f --- /dev/null +++ b/test/scout_apm/logging/otlp/encoder_test.exs @@ -0,0 +1,96 @@ +defmodule ScoutApm.Logging.OTLP.EncoderTest do + use ExUnit.Case + + alias ScoutApm.Logging.OTLP.Encoder + alias ScoutApm.Logging.LogRecord + + describe "encode/1" do + test "encodes a list of log records" do + record = LogRecord.new(:info, "Test message", %{"key" => "value"}) + result = Encoder.encode([record]) + + assert is_map(result) + assert Map.has_key?(result, "resourceLogs") + + [resource_log] = result["resourceLogs"] + assert Map.has_key?(resource_log, "resource") + assert Map.has_key?(resource_log, "scopeLogs") + + [scope_log] = resource_log["scopeLogs"] + assert Map.has_key?(scope_log, "scope") + assert Map.has_key?(scope_log, "logRecords") + + [log_record] = scope_log["logRecords"] + assert log_record["severityText"] == "INFO" + assert log_record["severityNumber"] == 9 + assert log_record["body"]["stringValue"] == "Test message" + end + + test "encodes empty list" do + result = Encoder.encode([]) + + [resource_log] = result["resourceLogs"] + [scope_log] = resource_log["scopeLogs"] + assert scope_log["logRecords"] == [] + end + end + + describe "encode_log_record/1" do + test "encodes basic log record" do + record = LogRecord.new(:warning, "Warning message") + result = Encoder.encode_log_record(record) + + assert result["severityText"] == "WARN" + assert result["severityNumber"] == 13 + assert result["body"]["stringValue"] == "Warning message" + assert is_integer(result["timeUnixNano"]) + assert is_integer(result["observedTimeUnixNano"]) + end + + test "encodes attributes" do + record = LogRecord.new(:info, "Test", %{"string_key" => "value", "int_key" => 42}) + result = Encoder.encode_log_record(record) + + assert Map.has_key?(result, "attributes") + attrs = result["attributes"] + + string_attr = Enum.find(attrs, &(&1["key"] == "string_key")) + assert string_attr["value"]["stringValue"] == "value" + + int_attr = Enum.find(attrs, &(&1["key"] == "int_key")) + assert int_attr["value"]["intValue"] == "42" + end + + test "encodes boolean attributes" do + record = LogRecord.new(:info, "Test", %{"bool_key" => true}) + result = Encoder.encode_log_record(record) + + attrs = result["attributes"] + bool_attr = Enum.find(attrs, &(&1["key"] == "bool_key")) + assert bool_attr["value"]["boolValue"] == true + end + + test "encodes float attributes" do + record = LogRecord.new(:info, "Test", %{"float_key" => 3.14}) + result = Encoder.encode_log_record(record) + + attrs = result["attributes"] + float_attr = Enum.find(attrs, &(&1["key"] == "float_key")) + assert float_attr["value"]["doubleValue"] == 3.14 + end + + test "does not include empty attributes" do + record = LogRecord.new(:info, "Test", %{}) + result = Encoder.encode_log_record(record) + + refute Map.has_key?(result, "attributes") + end + + test "does not include dropped count when zero" do + record = LogRecord.new(:info, "Test") + result = Encoder.encode_log_record(record) + + refute Map.has_key?(result, "droppedAttributesCount") + end + end +end diff --git a/test/scout_apm/logging/otlp/severity_test.exs b/test/scout_apm/logging/otlp/severity_test.exs new file mode 100644 index 0000000..f131b03 --- /dev/null +++ b/test/scout_apm/logging/otlp/severity_test.exs @@ -0,0 +1,100 @@ +defmodule ScoutApm.Logging.OTLP.SeverityTest do + use ExUnit.Case + + alias ScoutApm.Logging.OTLP.Severity + + describe "to_number/1" do + test "maps debug to 5" do + assert Severity.to_number(:debug) == 5 + end + + test "maps info to 9" do + assert Severity.to_number(:info) == 9 + end + + test "maps notice to 11" do + assert Severity.to_number(:notice) == 11 + end + + test "maps warning to 13" do + assert Severity.to_number(:warning) == 13 + end + + test "maps warn to 13" do + assert Severity.to_number(:warn) == 13 + end + + test "maps error to 17" do + assert Severity.to_number(:error) == 17 + end + + test "maps critical to 21" do + assert Severity.to_number(:critical) == 21 + end + + test "maps alert to 21" do + assert Severity.to_number(:alert) == 21 + end + + test "maps emergency to 21" do + assert Severity.to_number(:emergency) == 21 + end + + test "maps unknown to 0" do + assert Severity.to_number(:unknown) == 0 + end + end + + describe "to_text/1" do + test "maps debug to DEBUG" do + assert Severity.to_text(:debug) == "DEBUG" + end + + test "maps info to INFO" do + assert Severity.to_text(:info) == "INFO" + end + + test "maps warning to WARN" do + assert Severity.to_text(:warning) == "WARN" + end + + test "maps error to ERROR" do + assert Severity.to_text(:error) == "ERROR" + end + + test "maps critical to FATAL" do + assert Severity.to_text(:critical) == "FATAL" + end + + test "maps unknown to UNSPECIFIED" do + assert Severity.to_text(:unknown) == "UNSPECIFIED" + end + end + + describe "meets_level?/2" do + test "error meets info level" do + assert Severity.meets_level?(:error, :info) == true + end + + test "debug does not meet info level" do + assert Severity.meets_level?(:debug, :info) == false + end + + test "info meets info level" do + assert Severity.meets_level?(:info, :info) == true + end + + test "warning meets debug level" do + assert Severity.meets_level?(:warning, :debug) == true + end + end + + describe "levels/0" do + test "returns all levels in order" do + levels = Severity.levels() + assert :emergency in levels + assert :debug in levels + assert length(levels) == 8 + end + end +end diff --git a/test/scout_apm/logging_test.exs b/test/scout_apm/logging_test.exs new file mode 100644 index 0000000..7b14822 --- /dev/null +++ b/test/scout_apm/logging_test.exs @@ -0,0 +1,56 @@ +defmodule ScoutApm.LoggingTest do + use ExUnit.Case + + alias ScoutApm.Logging + + describe "attach/0 and detach/0" do + test "attaches and detaches handler" do + # Start fresh + Logging.detach() + refute Logging.attached?() + + # Attach + assert Logging.attach() == :ok + assert Logging.attached?() + + # Attaching again is idempotent + assert Logging.attach() == :ok + assert Logging.attached?() + + # Detach + assert Logging.detach() == :ok + refute Logging.attached?() + + # Detaching again is idempotent + assert Logging.detach() == :ok + refute Logging.attached?() + end + end + + describe "enabled?/0" do + test "returns false by default" do + # Default config has logs_enabled: false + assert Logging.enabled?() == false + end + end + + describe "queue_size/0" do + test "returns current queue size" do + size = Logging.queue_size() + assert is_integer(size) + assert size >= 0 + end + end + + describe "flush/0" do + test "flushes without error" do + assert Logging.flush() == :ok + end + end + + describe "drain/1" do + test "drains without error" do + assert Logging.drain(1000) == :ok + end + end +end diff --git a/test/scout_apm/plugs/controller_timer_test.exs b/test/scout_apm/plugs/controller_timer_test.exs index 78c0d3c..60989a4 100644 --- a/test/scout_apm/plugs/controller_timer_test.exs +++ b/test/scout_apm/plugs/controller_timer_test.exs @@ -1,6 +1,6 @@ defmodule ScoutApm.Plugs.ControllerTimerTest do + import Plug.Test use ExUnit.Case - use Plug.Test alias ScoutApm.Plugs.ControllerTimer setup do diff --git a/test/support/templates/simple.html.heex b/test/support/templates/simple.html.heex new file mode 100644 index 0000000..069a677 --- /dev/null +++ b/test/support/templates/simple.html.heex @@ -0,0 +1,4 @@ +
+

Hello from HEEx!

+

This is a test template.

+