From 06738d4327bf6b3eb58a941802633829759b2e67 Mon Sep 17 00:00:00 2001 From: Nathan Broadbent Date: Wed, 21 Oct 2026 15:52:03 +1300 Subject: [PATCH] Fix filtering edge cases and validation gaps --- AGENTS.md | 4 + CHANGELOG.md | 14 ++ DEVELOPMENT.md | 49 ++-- INTEGRATIONS.md | 220 ++++++------------ README.md | 2 +- SECURITY.md | 4 +- Taskfile.ruby.yml | 7 + Taskfile.yml | 2 +- docs/AGENTS.md | 2 +- docs/README.md | 24 +- docs/app/docs/configuration/page.tsx | 7 +- .../docs/filtering-sensitive-data/page.tsx | 13 +- docs/app/docs/integrations/sql/page.tsx | 6 +- docs/e2e/pages.test.ts | 2 +- docs/jest.integration.config.ts | 2 + docs/lib/integration-helpers.ts | 4 +- lib/log_struct/concerns/configuration.rb | 6 +- lib/log_struct/concerns/error_handling.rb | 11 + lib/log_struct/formatter.rb | 51 ++-- lib/log_struct/integrations/shrine.rb | 2 +- .../tagged_logging/formatter.rb | 8 +- lib/log_struct/param_filters.rb | 9 +- lib/log_struct/string_scrubber.rb | 13 +- logstruct.gemspec | 2 +- schemas/README.md | 56 ++--- scripts/generate_structs.rb | 37 +-- test/log_struct/configuration_test.rb | 35 +++ test/log_struct/formatter_test.rb | 63 ++++- test/log_struct/param_filters_test.rb | 85 +++++++ test/log_struct/string_scrubber_test.rb | 13 ++ test/workflows/generation_test.rb | 49 ++++ 31 files changed, 509 insertions(+), 293 deletions(-) create mode 100644 test/workflows/generation_test.rb diff --git a/AGENTS.md b/AGENTS.md index 1c110c5d..f32f6a15 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -8,6 +8,7 @@ 4. **This rule must ALWAYS be followed no matter what** 5. **`additional_data` is ONLY for unknown and dynamic fields that a user or integration might send. IF YOU KNOW THE NAME OF A FIELD, IT GOES IN THE SCHEMA. NEVER use `additional_data` for known fields.** 6. **NEVER run `git tag` without `-m` flag** - it opens an interactive editor and freezes. Always use: `git tag -a v0.1.7 -m "Release v0.1.7"` +7. **Filter failures must protect the value.** If a key or path filter raises and the error mode lets logging continue, filter the value. Apply size and depth limits before traversing values that will not be logged. ## Commands @@ -36,6 +37,7 @@ All commands use [Task](https://taskfile.dev) - run `task --list` to see all ava **Rails Integration Tests**: Located in `rails_test_app/templates/test/integration/`. The script automatically copies template files to the test app when you run `scripts/rails_tests.sh`. **FORCE_RECREATE**: Do NOT use `FORCE_RECREATE=true` unless absolutely necessary. It deletes the entire test app and recreates from scratch, which is slow. Only needed when: + - Gemfile changes require reinstalling gems - Something is fundamentally broken with the cached app - Rails version changes (but the script auto-detects this anyway) @@ -70,6 +72,7 @@ For template file changes (tests, rake tasks, etc.), just run `scripts/rails_tes - Generate all (structs + catalog): `task generate` - Generate Sorbet RBI files: `task ruby:tapioca` +- Verify committed Sorbet RBI files: `task ruby:tapioca:verify` (also part of `task ci`). Keep annotation updates separate from checks; downloading them while typechecking makes results depend on upstream changes and task timing. - Generate spellcheck dictionary: `scripts/generate_lockfile_words.sh` - Check generated files are up to date: `task ruby:check-generated` @@ -168,6 +171,7 @@ You do not need to check if these are defined with `defined?` - they are guarant What's left: splatting an Array or Hash whose size Sorbet doesn't know, a duck-typed call after `respond_to?` on another library's object, a `Minitest::Mock`, and a test that passes a wrong type on purpose. + - Don't call `def` inside a method definition in tests (or anywhere). Use mocks or stubs. - For modules included in other classes, use `requires_ancestor` - Custom type overrides belong in `sorbet/rbi/overrides/` diff --git a/CHANGELOG.md b/CHANGELOG.md index ac9bfc31..365b913b 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,20 @@ All notable changes to this project will be documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/), and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.html). +## [Unreleased] + +### Fixed + +- **Filtering**: Nested URL query parameters such as `password[]` and `token[value]` are filtered, including URL-encoded names and paths in Rails' `filter_parameters`. +- **Filtering**: Basic credentials are scrubbed even when their Base64 encoding is shorter than eight characters. +- **Filtering**: Symbols beyond the nesting limit are summarized instead of being written without scrubbing. +- **Filtering**: When a key or path matcher raises and error handling lets logging continue, its value is filtered. This also applies to Rails filter blocks. +- **Errors**: A failed filter or scrubber does not keep queuing or reporting errors when it fails again while formatting its own error line or report context. +- **Formatting**: Hash keys are normalized during filtering, so arrays, hashes and filtered values are no longer copied recursively before size limits are applied. Circular references are summarized at their first recurrence. +- **Docs**: Correct the supported security release series and contributor instructions for releases, generated log types and schema fields. Describe size limits as limits per value, not a guarantee on total formatting time. Ensure the site's integration tests run when a local Watchman installation is broken. +- **Development**: `task ci` verifies committed RBI files, matching GitHub CI, instead of downloading new annotations concurrently with typechecking. +- **Generation**: A failed formatter or Sorbet JSON export stops code generation instead of leaving incomplete artifacts with a successful exit status. + ## [0.2.1] - 2026-10-18 ### Fixed diff --git a/DEVELOPMENT.md b/DEVELOPMENT.md index 8ff11f6d..128b551e 100644 --- a/DEVELOPMENT.md +++ b/DEVELOPMENT.md @@ -84,6 +84,7 @@ However, some apps might skip certain parts of Rails and only require what they - `defined?(::ActionMailer)` - `defined?(::ActiveJob)` - `defined?(::ActiveStorage)` +- `defined?(::ActiveRecord)` And you always need to check for any third-party gems that are not part of Rails: @@ -109,7 +110,8 @@ And you always need to check for any third-party gems that are not part of Rails - Ensure all tests pass before submitting a pull request - Regular tests: `scripts/test.rb` - Rails integration tests: `scripts/rails_tests.sh` -- You can specify Rails version for integration tests: `RAILS_VERSION=7.1.3 scripts/rails_tests.sh` +- You can specify Rails version for integration tests: `RAILS_VERSION=7.2.3 scripts/rails_tests.sh` +- Run `task ci` before submitting changes, and `cd docs && pnpm check` for changes to the docs site. ## Working with Sorbet and Tapioca @@ -152,7 +154,7 @@ And you always need to check for any third-party gems that are not part of Rails When typing modules that are included in other classes (like concerns, helpers, etc.), use the following approach: 1. Create an RBI file in `sorbet/rbi/overrides/` that mirrors the module's path -2. Use `requires_ancestor` to specify that a class includes a module +2. Use `requires_ancestor` to specify the class or module that a consumer must inherit from or include 3. For class methods added via `extend`, declare them in a separate `ClassMethods` module Example from `sorbet/rbi/overrides/log_struct/integrations/action_mailer/error_handling.rbi`: @@ -162,7 +164,8 @@ Example from `sorbet/rbi/overrides/log_struct/integrations/action_mailer/error_h # This tells Sorbet that any class including ErrorHandling will have these methods module LogStruct::Integrations::ActionMailer::ErrorHandling - requires_ancestor { ActionMailer::Base } + extend T::Helpers + requires_ancestor { ::ActionMailer::Base } # Instance methods available to including classes def log_and_ignore_error; end @@ -184,7 +187,8 @@ When using `ActiveSupport::Concern` with an `included` block, you need to use `T ```ruby module MyModule - extend ActiveSupport::Concern + extend ::ActiveSupport::Concern + extend T::Helpers requires_ancestor { ParentClass } @@ -302,31 +306,37 @@ end #### Common Sorbet Patterns -1. **Binding `self` in class methods**: +1. **Typing an instance yielded to a block**: ```ruby class MyClass + extend T::Sig + class << self extend T::Sig - sig { params(value: String).void } - def configure(value) - yield(new(value)) + sig { params(value: String, blk: T.proc.params(instance: MyClass).void).void } + def configure(value, &blk) + blk.call(new(value)) end end - sig { params(config: T.untyped).void } + sig { params(config: String).void } def initialize(config) - @config = config + @config = T.let(config, String) end + + sig { returns(String) } + attr_reader :config end MyClass.configure("test") do |instance| - T.bind(self, MyClass) - # Now you can call MyClass instance methods + puts instance.config end ``` + Yielding an instance does not change `self`. Use the block parameter; reserve `T.bind` for DSLs that change the block's receiver. + 2. **Typing procs and blocks**: ```ruby @@ -364,17 +374,12 @@ Remember: Taking shortcuts with Sorbet defeats the purpose of having static type ## Releasing -1. Update the version number in `lib/log_struct/version.rb` -2. Update the `CHANGELOG.md` file -3. Create a git tag for the version -4. Push the tag to GitHub -5. Build and push the gem to RubyGems +1. Update the version in `lib/log_struct/version.rb` and the release entry in `CHANGELOG.md`. +2. Run `task ci`, commit the changes, and merge them into `main`. +3. From a clean `main` checkout matching `origin/main`, run `task gem:release`. It creates and pushes an annotated version tag. +4. Review and approve the `release` environment in the **Release Gem + Sync Terraform Provider** GitHub Actions workflow. It waits for CI on the tagged commit and publishes through RubyGems trusted publishing. -```bash -# Update version in lib/log_struct/version.rb first! -bundle exec rake build -gem push pkg/logstruct-x.y.z.gem -``` +Use the workflow's `dry_run` option to validate the release without publishing. `task gem:build` builds a local package; do not push gems from a laptop. See [AGENTS.md](AGENTS.md#automated-releases-gem--provider) for the release workflow and provider synchronization. ## Documentation diff --git a/INTEGRATIONS.md b/INTEGRATIONS.md index 360a03c7..aaa2f0b4 100644 --- a/INTEGRATIONS.md +++ b/INTEGRATIONS.md @@ -1,143 +1,77 @@ -**Purpose** - -- Document how to add a new first‑class integration to LogStruct so it’s consistent, type‑safe, well‑tested, and shows up automatically in the docs docs with an auto‑generated example log. - -**High‑Level Flow** - -- Add a typed log structure under `lib/log_struct/log/` (so the docs generator picks it up). -- Add a configuration toggle in `ConfigStruct::Integrations` and wire it into `Integrations.setup_integrations` via the appropriate stage (`:non_middleware` for instrumentation hooks, `:middleware` when the integration inserts Rack middleware). -- Implement the integration under `lib/log_struct/integrations/…` to produce that log type. -- Add the dev dependency for the third‑party gem and generate RBIs with Tapioca. -- Add tests (unit + behavior) under `test/log_struct/integrations` and (if needed) `test/log_struct/log`. -- Add a short entry in the docs metadata (`docs/lib/integration-helpers.ts`). The Integrations page will render it automatically via `AllLogTypes`. -- Run type export to update the docs’ TypeScript types. - -**Conventions** - -- Files and naming: - - Log type: `lib/log_struct/log/.rb` (class `LogStruct::Log::`) - - Integration: `lib/log_struct/integrations/.rb` (module `LogStruct::Integrations::`) - - Optional submodules (e.g., `logger.rb`, `log_subscriber.rb`) live below a folder `lib/log_struct/integrations//`. - - Tests mirror structure under `test/log_struct/log` and `test/log_struct/integrations`. -- Type safety: - - Every Ruby file must be `# typed: strict` and use `T::Sig`. - - For integration setup signatures: `sig { params(config: LogStruct::Configuration).returns(T.nilable(TrueClass)) }`. - - Prefer real constants (the gem is a development dependency), but guard runtime with `defined?(::GemModule)` to be safe in user apps. -- Error handling: - - Never raise from the integration path; use `LogStruct.handle_exception(error, source: , context: {integration: :name})`. -- Logging: - - Produce a dedicated typed log struct (do NOT emit a generic/plain log). - - Message naming: concise and stable, e.g., `"ams.render"`, `"ahoy.track"`. - - Choose the correct `Source` (Rails/App/Job/Storage/…) and a suitable `Event` (`Event::Log` unless a more specific event applies). - -**Step‑by‑Step Checklist** - -1. Create the typed log struct - - File: `lib/log_struct/log/.rb` - - Include: `Interfaces::CommonFields`, `Interfaces::AdditionalDataField`, `SerializeCommon`, `MergeAdditionalDataFields`. - - Define required fields and defaults (e.g., `message`, specific properties for the integration), and implement `serialize` to add them to the output. - - Example skeleton: - - class LogStruct::Log::Example < T::Struct - extend T::Sig - include Interfaces::CommonFields - include Interfaces::AdditionalDataField - include SerializeCommon - include MergeAdditionalDataFields - - ExampleEvent = T.type_alias { Event::Log } - const :source, Source::Rails, default: T.let(Source::Rails, Source::Rails) - const :event, ExampleEvent, default: T.let(Event::Log, ExampleEvent) - const :level, Level, default: T.let(Level::Info, Level) - const :timestamp, Time, factory: -> { Time.now } - - const :message, String, default: "example.event" - const :detail, T.nilable(String), default: nil - const :additional_data, T::Hash[Symbol, T.untyped], default: {} - - sig { override.params(strict: T::Boolean).returns(T::Hash[Symbol, T.untyped]) } - def serialize(strict = true) - h = serialize_common(strict) - merge_additional_data_fields(h) - h[LOG_KEYS.fetch(:message)] = message - h[:detail] = detail if detail - h - end - end - -2. Register the log type - - In `lib/log_struct/log.rb`: - - `require_relative "log/"` - -3. Add a config toggle - - In `lib/log_struct/config_struct/integrations.rb`: - - `prop :enable_, T::Boolean, default: true` - - In `lib/log_struct/integrations.rb`: - - `require_relative "integrations/"` - - Call `Integrations::.setup(config)` inside `setup_integrations`, selecting the stage that matches your integration (`:non_middleware` for subscribers/hooks, `:middleware` for Rack additions). Most integrations belong in the default `:non_middleware` stage; only code that mutates the middleware stack should go in `:middleware`. - -4. Implement the integration - - File: `lib/log_struct/integrations/.rb` - - Guard on presence of the third‑party gem (`return nil unless defined?(::ThirdParty)`), subscribe/hook into events, build your typed log, and log it with `LogStruct.info(log)`. - - Use `handle_exception` on rescue. - -5. Add development dependency + RBIs - - In `logstruct.gemspec`, add the gem as a development dependency with a supported version: - - `spec.add_development_dependency "third_party_gem", "~> X.Y"` - - Run: - - `bundle install` - - `bundle exec tapioca gems` (commits RBIs under `sorbet/rbi/gems/...`). - -6. Tests - - Unit/behavior tests under `test/log_struct/integrations/_test.rb`. - - If the integration exposes a new log struct surface, add a focused test in `test/log_struct/log/_test.rb` when it adds non‑trivial serialization. - - Prefer real gem objects with small fakes only where necessary; the gem is available as a dev dependency. - - Assertions should inspect `as_json` and verify: - - `src`, `evt`, `lvl`, `ts` exist - - `msg` matches the agreed name - - Integration‑specific fields are present and correct - -7. Docs - - No custom sections in the Integrations page. - - The Integrations page lists all `AllLogTypes` with titles/descriptions from `docs/lib/integration-helpers.ts`. - - Add an entry to `getLogTypeInfo` for your new log type (title, concise description, optional `configuration_code: 'integrations_configuration'`). - - Run the type export to regenerate the docs’ TypeScript assets so example logs render: - - `ruby scripts/generate_structs.rb` - -8. Sorbet + CI - - Run `scripts/typecheck.sh` (must be clean). - - Run `scripts/test.rb` and `scripts/rails_tests.sh` (must be green). - - CI will enforce Tapioca verification and coverage threshold (80%+ merged). - -**Patterns to Follow (Examples)** - -- GoodJob: - - Log type: `lib/log_struct/log/good_job.rb` - - Integration: `lib/log_struct/integrations/good_job.rb` (+ `logger.rb`) - - Toggle: `enable_goodjob` -- SQL (ActiveRecord): - - Log type: `lib/log_struct/log/sql.rb` - - Integration: `lib/log_struct/integrations/active_record.rb` - - Toggle: `enable_sql_logging` -- ActiveModelSerializers: - - Log type: `lib/log_struct/log/active_model_serializers.rb` (msg: "ams.render") - - Integration: `lib/log_struct/integrations/active_model_serializers.rb` - - Toggle: `enable_active_model_serializers` -- Ahoy: - - Log type: `lib/log_struct/log/ahoy.rb` (msg: "ahoy.track") - - Integration: `lib/log_struct/integrations/ahoy.rb` - - Toggle: `enable_ahoy` - -**Gotchas** - -- Don’t emit generic/plain logs for integrations that deserve a first‑class type. -- Keep message names short and stable; avoid dumping raw payloads into `msg`. -- Don’t raise in integration hooks; always call `handle_exception` with the correct `Source`. - -**One‑Time Commands (after adding or changing log types)** - -- `bundle install` -- `bundle exec tapioca gems` -- `ruby scripts/generate_structs.rb` -- `scripts/typecheck.sh` -- `scripts/test.rb` and (optionally) `scripts/rails_tests.sh` +# Adding an integration + +Built-in log types come from the YAML files in `schemas/log_sources/`. Never edit the generated Ruby +classes under `lib/log_struct/log/` or the TypeScript files under `docs/generated/` by hand. + +## Define the log type + +1. Add a schema under `schemas/log_sources/.yml`. See [schemas/README.md](schemas/README.md) + for the schema format. Use an existing `Source` and `Event`, or add their enum values under + `lib/log_struct/enums/` first. Every known field belongs in the schema; `additional_data` is for + unknown fields supplied by an app or integration. +2. Add any new field names and their serialized keys to `lib/log_struct/enums/log_field.rb`. +3. Add the new source's require to `lib/log_struct/log.rb`. +4. Run `task generate` to generate the Ruby classes, TypeScript types, field schema and provider catalog. The script writes the Ruby classes before loading them for the type export. + +For example, the Ahoy schema defines a single `LogStruct::Log::Ahoy` class: + +```yaml +source: Ahoy +consts: + source: Source::App +events: + Log: + fields: + Message: String + AhoyEvent: String + Properties: + type: 'T::Hash[Symbol, T.untyped]' + required: false +``` + +Multiple events produce a parent file and one class per event, such as `LogStruct::Log::ActiveJob::Start`. +Fields are required unless the schema sets `default_required: false` or an individual field sets +`required: false`. + +## Connect the integration + +1. Add `prop :enable_, T::Boolean, default: true` to `ConfigStruct::Integrations`. +2. Implement `LogStruct::Integrations::` under `lib/log_struct/integrations/.rb`. + Extend `IntegrationInterface`, and give `setup` this signature: + + ```ruby + sig { override.params(config: LogStruct::Configuration).returns(T.nilable(T::Boolean)) } + ``` + + Return `nil` when LogStruct or the integration is disabled, or its optional gem is absent. Use + `::` for external constants. Subscribe to the gem's events, build the generated log struct, and + pass it to `LogStruct.info`, `warn` or `error` as appropriate. + +3. Require the integration from `lib/log_struct/integrations.rb` and call its setup in the appropriate + stage: `:non_middleware` for subscribers and hooks, `:middleware` for Rack stack changes. +4. When replacing an existing log subscriber, detach the original so each event is logged once. + Keep exceptions and return values behaving as the underlying gem expects. Use + `LogStruct.handle_exception(error, source: Source::Internal)` for failures inside the integration; + its configured mode decides whether to raise, log or report the error. +5. Add optional third-party gems as development dependencies in `logstruct.gemspec`, run `bundle install`, + and generate their RBIs with `bundle exec tapioca gems`. They must not become required runtime + dependencies just to support an optional integration. + +Follow `integrations/ahoy.rb` for a small integration, or `integrations/active_job/log_subscriber.rb` +for an integration with several events. + +## Test and document it + +- Add tests under `test/log_struct/integrations/`. Exercise real events and inspect the emitted JSON: + source, event, level, timestamps, expected fields, filtering, errors and duplicate lines. +- Add Rails integration tests under `rails_test_app/templates/test/integration/` where boot order or + framework behavior matters. The test runner copies these templates into its generated app. +- Add the toggle to the configuration examples in `test/code_examples/configuration_test.rb`, which + supply the code shown on the docs site. +- Add the title, description and any detail-page link to `docs/lib/integration-helpers.ts`. + `AllLogTypes` supplies the integration list. Update `docs/lib/gem-descriptions.ts` for an optional gem. +- Run `task generate`, `task ci`, and `cd docs && pnpm check` before calling the work ready. + +The generator writes the provider catalog under `terraform-provider-logstruct/pkg/data/`, a path +ignored by this repository. When working in the separate provider checkout, commit its changes from +that repository. diff --git a/README.md b/README.md index 8b595fa5..aa61bff4 100644 --- a/README.md +++ b/README.md @@ -28,7 +28,7 @@ any other log platform. Sensitive values are filtered and scrubbed before a line `Bearer` and `Basic` credentials and sensitive URL query params (`?token=`) are replaced too. IP and MAC address scrubbing are opt-in. - **Limits.** Huge values are cut down (100 keys per Hash, 10 items per Array, 20 lines per backtrace, 32 KB per - String by default), so one large request body can't slow down your logging. + String by default), reducing log size and the work spent formatting large values. - **Error handling.** A mode for each kind of error decides whether it's raised, logged or reported, and whether that differs between development and production. Reports go to Sentry, Bugsnag, Rollbar, Honeybadger or your own reporter. diff --git a/SECURITY.md b/SECURITY.md index 55a9d9c2..a1b4ee9f 100644 --- a/SECURITY.md +++ b/SECURITY.md @@ -18,5 +18,5 @@ Security fixes go into the latest minor release. Please upgrade to it before rep | Version | Supported | | ------- | --------- | -| 0.1.x | Yes | -| < 0.1 | No | +| 0.2.x | Yes | +| < 0.2 | No | diff --git a/Taskfile.ruby.yml b/Taskfile.ruby.yml index 979b9ddd..103e8652 100644 --- a/Taskfile.ruby.yml +++ b/Taskfile.ruby.yml @@ -17,6 +17,13 @@ tasks: - bundle exec tapioca dsl - bundle exec tapioca annotations + tapioca:verify: + desc: Verify committed RBI files without downloading new annotations + deps: [generate] + cmds: + - bundle exec tapioca gems --verify + - bundle exec tapioca dsl --verify + typecheck: desc: Run Sorbet type checking deps: [generate] diff --git a/Taskfile.yml b/Taskfile.yml index cb849c01..231bf6fe 100644 --- a/Taskfile.yml +++ b/Taskfile.yml @@ -63,7 +63,7 @@ tasks: - spellcheck - docs:test - test - - ruby:tapioca + - ruby:tapioca:verify fix: desc: Auto-fix lint issues then run the full validation workflow (replaces scripts/all_write.sh) diff --git a/docs/AGENTS.md b/docs/AGENTS.md index 540b26b1..0af4622e 100644 --- a/docs/AGENTS.md +++ b/docs/AGENTS.md @@ -29,7 +29,7 @@ - Components: PascalCase files in `components/`; hooks start with `use*`. - Route segments and non-component utilities: kebab-case or lowerCamelCase as idiomatic for Next.js. - 2-space indentation; avoid default exports for shared components. -- ESLint config: `eslint.config.mjs`. Fix issues as reported by `pnpm lint`. +- Biome config: `biome.json`. Fix issues as reported by `pnpm lint`. - Styling via Tailwind CSS v4; keep atomic classes close to components. ## Testing Guidelines diff --git a/docs/README.md b/docs/README.md index 7d2850f9..078a952e 100644 --- a/docs/README.md +++ b/docs/README.md @@ -13,24 +13,34 @@ This is the documentation website for the LogStruct gem, built with Next.js and ### Prerequisites -- Node.js (version 18 or higher) -- pnpm (version 9 or higher) +- Node.js 22 and pnpm 10.18.3 (the versions used in CI) +- The repository's Ruby version, Bundler and Task, with `bundle install` completed at the repository root ### Getting Started -1. Install dependencies: +1. Generate the log types, test coverage and API documentation from the repository root: + +```bash +task generate +task test +task yard:generate +``` + +The homepage reads `public/coverage/coverage.json`, and the navigation links to `public/yard/`. These are generated artifacts, so a clean checkout needs them before serving or building the site. + +2. Install the docs dependencies from this directory: ```bash pnpm install ``` -2. Start the development server: +3. Start the development server: ```bash pnpm dev ``` -3. Open [http://localhost:3001](http://localhost:3001) to view the docs in your browser. +4. Open [http://localhost:3001](http://localhost:3001) to view the docs in your browser. ### Building for Production @@ -44,7 +54,7 @@ This will generate static HTML files in the `out` directory that can be deployed ## Deployment -This site is configured to deploy to GitHub Pages automatically through GitHub Actions. Any changes pushed to the main branch will trigger a deployment. +This site deploys to GitHub Pages through GitHub Actions after CI passes on `main`, using that CI run's coverage report. To manually deploy: @@ -71,3 +81,5 @@ To add or update documentation: 1. Create or edit files in the `app/docs` directory 2. Each page should be a React component that exports a default function 3. For new sections, update the sidebar in `app/docs/layout.tsx` +4. Keep Ruby examples in `test/code_examples/` and display them with `RubyCodeExample`, so the Ruby suite checks them +5. Run `task ci` from the repository root and `pnpm check` here (types, lint, static build, integration tests and browser tests) diff --git a/docs/app/docs/configuration/page.tsx b/docs/app/docs/configuration/page.tsx index b6b90703..2abc8897 100644 --- a/docs/app/docs/configuration/page.tsx +++ b/docs/app/docs/configuration/page.tsx @@ -180,9 +180,10 @@ LOGSTRUCT_ENABLED=false bin/rails test`} Limits

- LogStruct writes only part of very large values, so a huge request body or Hash can't - slow down the thread that writes your logs. Long strings are scrubbed before they're - cut. + LogStruct writes only part of very large values to reduce log size and formatting work. + These are limits on each value, not a total size or time limit for a line. Custom + serializers and filters can still do expensive work. Long strings are scrubbed before + they're cut.

diff --git a/docs/app/docs/filtering-sensitive-data/page.tsx b/docs/app/docs/filtering-sensitive-data/page.tsx index b2bd2f48..99317b77 100644 --- a/docs/app/docs/filtering-sensitive-data/page.tsx +++ b/docs/app/docs/filtering-sensitive-data/page.tsx @@ -208,8 +208,9 @@ const SCRUBBERS: Scrubber[] = [ <> In a URL's query string (after a ?), the value of each param whose name would be filtered as a key, and of OAuth's code. A name like{' '} - user[password] is checked by its last part, written plainly or URL-encoded. - Replaced with [FILTERED]. + user[password] is checked by each part, written plainly or URL-encoded, so{' '} + password[] and token[value] are filtered too. Dotted Rails filters + match the nested path. Replaced with [FILTERED]. ), examples: [ @@ -219,6 +220,8 @@ const SCRUBBERS: Scrubber[] = [ '/signup?user[password]=[FILTERED]&user[name]=Jo', ], ['/oauth/callback?code=4/0AY0e&state=xyz', '/oauth/callback?code=[FILTERED]&state=xyz'], + ['/login?password[]=hunter2', '/login?password[]=[FILTERED]'], + ['/login?token[value]=abc123', '/login?token[value]=[FILTERED]'], ['password=hunter2&user=jo', 'password=hunter2&user=jo', 'No ? before the params'], ], }, @@ -652,6 +655,12 @@ export default function FilteringSensitiveDataPage() { .

+

+ If a key or path filter raises, LogStruct handles the error using{' '} + error_handling_modes.logstruct_errors. When that mode lets logging continue, + the value is filtered. A failing filter never counts as permission to write the value. +

+ String Scrubbing

LogStruct scans every String it writes for data in known formats and replaces it, whatever diff --git a/docs/app/docs/integrations/sql/page.tsx b/docs/app/docs/integrations/sql/page.tsx index 96b6cfb2..85ee737f 100644 --- a/docs/app/docs/integrations/sql/page.tsx +++ b/docs/app/docs/integrations/sql/page.tsx @@ -216,9 +216,9 @@ export default function SqlIntegrationPage() {

  • Other strings are written as [FILTERED] when they look like a secret: longer - than 50 characters, 32 or more hex digits, 20 or more Base64 characters, a JWT, a{' '} - Bearer token, or text containing password, secret,{' '} - token, key or auth. + than 50 characters with no whitespace, 32 or more hex digits, 20 or more Base64 + characters, a JWT, or a Bearer token. Merely containing a word such as{' '} + password or key does not make a value sensitive.
  • What's left is scrubbed like any other value.
    • diff --git a/docs/e2e/pages.test.ts b/docs/e2e/pages.test.ts index 90c1ec80..fffd3f3c 100644 --- a/docs/e2e/pages.test.ts +++ b/docs/e2e/pages.test.ts @@ -80,7 +80,7 @@ async function get(path: string): Promise { describe('Site integration pages', () => { test('home page renders', async () => { const html = await get('/'); - expect(html).toContain('Zero-config JSON logging for Ruby on Rails'); + expect(html).toContain('Zero-config structured logging for Ruby on Rails'); expect(html).toContain('Get Started'); }); diff --git a/docs/jest.integration.config.ts b/docs/jest.integration.config.ts index d116fde4..d0b93643 100644 --- a/docs/jest.integration.config.ts +++ b/docs/jest.integration.config.ts @@ -5,6 +5,8 @@ const config: Config = { testEnvironment: 'node', testMatch: ['**/e2e/**/*.test.(ts|js)'], verbose: true, + // Match the unit runner: a broken Watchman install can exit without running tests. + watchman: false, // Integration tests can be slower due to build/start testTimeout: 120000, }; diff --git a/docs/lib/integration-helpers.ts b/docs/lib/integration-helpers.ts index 2823bfa9..16ba2fe6 100644 --- a/docs/lib/integration-helpers.ts +++ b/docs/lib/integration-helpers.ts @@ -33,7 +33,7 @@ export function getLogTypeInfo(logType: LogType): { return { title: 'ActionMailer', description: - "Logs each mail before it's sent (delivery) and after (delivered), with the mailer, the action and the record IDs you choose with actionmailer_id_mapping. A delivery error is an error line, and what happens next (raise, report, retry) follows error_handling_modes.", + "Logs each mail before it's sent (delivery) and after (delivered), with the mailer, the action and the record IDs you choose with actionmailer_id_mapping. A delivery error is logged and raised again by default; a mailer's rescue_from handlers can choose to ignore or report it instead.", docsPath: '/docs/integrations/action-mailer', }; @@ -71,7 +71,7 @@ export function getLogTypeInfo(logType: LogType): { return { title: 'Security Logging', description: - 'Logs requests that HostAuthorization blocked, failed CSRF checks and IP spoofing attempts as security lines, and reports them according to error_handling_modes.security_errors.', + 'Logs requests that HostAuthorization blocked, failed CSRF checks and IP spoofing attempts as security lines. CSRF and IP spoofing errors are reported according to error_handling_modes.security_errors; blocked hosts are only logged.', docsPath: '/docs/integrations/security', }; diff --git a/lib/log_struct/concerns/configuration.rb b/lib/log_struct/concerns/configuration.rb index 24a15e04..28e3bb5d 100644 --- a/lib/log_struct/concerns/configuration.rb +++ b/lib/log_struct/concerns/configuration.rb @@ -260,7 +260,7 @@ def build_path_block_matcher(filter) !!result || (value.is_a?(String) && value != original_value) rescue => e handle_filter_error(e, filter, original_key || "") - false + true end ConfigStruct::PathFilterMatcher.new(callable: callable, label: filter.inspect) end @@ -291,11 +291,11 @@ def build_callable_filter_matcher(filter) !!filter.call(key) rescue => e handle_filter_error(e, filter, key) - false + true end rescue => e handle_filter_error(e, filter, key) - false + true end ConfigStruct::FilterMatcher.new(callable: callable, label: filter.inspect) end diff --git a/lib/log_struct/concerns/error_handling.rb b/lib/log_struct/concerns/error_handling.rb index 405c2fc1..9b42400f 100644 --- a/lib/log_struct/concerns/error_handling.rb +++ b/lib/log_struct/concerns/error_handling.rb @@ -78,10 +78,15 @@ def report_error(error, source:, context: nil) # request's parameters or a mail's recipients sig { params(context: T.nilable(T::Hash[Symbol, T.untyped])).returns(T.nilable(T::Hash[Symbol, T.untyped])) } def filtered_context(context) + previous_internal_error = Thread.current[:logstruct_formatting_internal_error] + # The same filter may fail on the error's context. Keep that failure from reporting itself. + Thread.current[:logstruct_formatting_internal_error] = true return context if context.nil? || context.empty? filtered = Formatter.new.process_values(context) filtered.is_a?(Hash) ? filtered : {} + ensure + Thread.current[:logstruct_formatting_internal_error] = previous_internal_error end # Handle an error according to the configured error handling mode (log, report, raise, etc). @@ -95,6 +100,12 @@ def handle_exception(error, source:, context: nil, log: true) raise(error) if !LogStruct.is_production? end + # A broken filter or scrubber can also fail on its own error line. Enqueuing another error + # there would repeat forever on SemanticLogger's writer thread. Raise modes still raise. + if source == Source::Internal && Thread.current[:logstruct_formatting_internal_error] && mode != ErrorHandlingMode::Raise + return + end + case mode when ErrorHandlingMode::Ignore # Do nothing diff --git a/lib/log_struct/formatter.rb b/lib/log_struct/formatter.rb index 41babe3e..3f0236d8 100644 --- a/lib/log_struct/formatter.rb +++ b/lib/log_struct/formatter.rb @@ -194,12 +194,12 @@ def valid_utf8(string) StringScrubber.valid_utf8(string) end - # A String or Symbol key as valid UTF-8 (symbolize_keys makes Symbols of binary String keys) + # Normalize only keys that will be logged, after applying the size limits. sig { params(key: T.untyped).returns(T.untyped) } def valid_utf8_key(key) case key when String - valid_utf8(key) + valid_utf8(key).to_sym when Symbol name = key.name fixed = valid_utf8(name) @@ -232,31 +232,6 @@ def scrub_limited_string(string) "#{kept}... (cut from #{string.bytesize} bytes)" end - # Like deep_symbolize_keys, but stops at circular references and at the depth where - # process_values stops, leaving those values for process_values to summarize - sig { params(value: T.untyped, recursion_depth: Integer, ancestors: T::Hash[T.untyped, T::Boolean]).returns(T.untyped) } - def symbolize_keys(value, recursion_depth: 0, ancestors: {}.compare_by_identity) - return value if recursion_depth > MAX_RECURSION_DEPTH || ancestors.key?(value) - - case value - when Hash - ancestors[value] = true - result = value.each_with_object({}) do |(key, nested_value), symbolized| - symbol_key = key.respond_to?(:to_sym) ? key.to_sym : key - symbolized[symbol_key] = symbolize_keys(nested_value, recursion_depth: recursion_depth + 1, ancestors: ancestors) - end - ancestors.delete(value) - result - when Array - ancestors[value] = true - result = value.map { |item| symbolize_keys(item, recursion_depth: recursion_depth + 1, ancestors: ancestors) } - ancestors.delete(value) - result - else - value - end - end - # Describes a value without filtering, scrubbing or serializing it, so that values which # couldn't be processed are never logged raw. Hashes and arrays are not serialized because # they may contain circular references. @@ -267,16 +242,16 @@ def summarize_unprocessed_value(arg) {_filtered: {_class: arg.class.name, _keys_count: arg.size}} when Array {_filtered: {_class: arg.class.name, _count: arg.size}} - when String + when String, Symbol {_filtered: {_class: arg.class.name}} - when Numeric, Symbol, TrueClass, FalseClass, NilClass + when Numeric, TrueClass, FalseClass, NilClass arg else {_filtered: {_class: arg.class.name}} end end - sig { params(log_value: T.untyped, time: Time).returns(T::Hash[Symbol, T.untyped]) } + sig { params(log_value: T.untyped, time: Time).returns(T::Hash[T.untyped, T.untyped]) } def log_value_to_hash(log_value, time:) case log_value when Log::Interfaces::CommonFields @@ -284,12 +259,10 @@ def log_value_to_hash(log_value, time:) log_value.serialize when T::Struct - # Default T::Struct.serialize methods returns a hash with string keys, so convert them to symbols - symbolize_keys(log_value.serialize) + log_value.serialize when Hash - # Use hash as is and convert string keys to symbols - symbolize_keys(log_value) + log_value when Exception # logger.error(exception): its class, message and backtrace @@ -357,9 +330,15 @@ def log_value_to_hash(log_value, time:) ).returns(String) end def call(severity, time, progname, log_value, request_id: nil, context: nil, tags: nil) + previous_internal_error = Thread.current[:logstruct_formatting_internal_error] level_enum = Level.from_severity(severity) data = log_value_to_hash(log_value, time: time) + source = data[:src] || data["src"] + event = data[:evt] || data["evt"] + if [Source::Internal, :logstruct, "logstruct"].include?(source) && [Event::Error, :error, "error"].include?(event) + Thread.current[:logstruct_formatting_internal_error] = true + end # Filter params, scrub sensitive values, format ActiveJob GlobalID arguments data = process_values(data) @@ -376,6 +355,8 @@ def call(severity, time, progname, log_value, request_id: nil, context: nil, tag rescue SystemStackError, StandardError => e unwritable_line_json(data, e) end + ensure + Thread.current[:logstruct_formatting_internal_error] = previous_internal_error end # A line that can't be written as JSON is replaced by one that says so, instead of being lost @@ -420,7 +401,7 @@ def add_metadata(data, progname:, request_id:, context:, tags:) if request_id.is_a?(String) && !request_id.empty? && !data.key?(:req_id) metadata[:req_id] = request_id end - metadata[:ctx] = symbolize_keys(context) if context.present? + metadata[:ctx] = context if context.present? return if metadata.empty? processed = process_values(metadata) diff --git a/lib/log_struct/integrations/shrine.rb b/lib/log_struct/integrations/shrine.rb index 0cdb600e..86249060 100644 --- a/lib/log_struct/integrations/shrine.rb +++ b/lib/log_struct/integrations/shrine.rb @@ -104,7 +104,7 @@ def self.setup(config) end # Upload options with the file names taken out of a Content-Disposition (upload_options: - # {content_disposition: ...}, which the upload_options plugin often sets): they can name a person + # `{content_disposition: ...}`, which the upload_options plugin often sets): they can name a person sig { params(options: T.untyped).returns(T.untyped) } def self.without_file_names(options) return options unless options.is_a?(Hash) diff --git a/lib/log_struct/monkey_patches/active_support/tagged_logging/formatter.rb b/lib/log_struct/monkey_patches/active_support/tagged_logging/formatter.rb index d09b99f4..727fc089 100644 --- a/lib/log_struct/monkey_patches/active_support/tagged_logging/formatter.rb +++ b/lib/log_struct/monkey_patches/active_support/tagged_logging/formatter.rb @@ -6,8 +6,8 @@ # Monkey-patch ActiveSupport::TaggedLogging::Formatter to work with structured logging. # # Problem: Rails' TaggedLogging prepends tags as text and converts messages to strings. -# When we pass a hash to super(), Rails does "#{tags_text}#{msg}" which calls .to_s -# on the hash, producing Ruby inspect format {message: "..."} instead of valid JSON. +# When we pass a hash to super(), Rails does `"#{tags_text}#{msg}"` which calls .to_s +# on the hash, producing Ruby inspect format `{message: "..."}` instead of valid JSON. # # Solution: When LogStruct is enabled, we add tags as a hash entry and delegate to # LogStruct::Formatter for proper JSON serialization with filtering and standard fields. @@ -58,4 +58,6 @@ def logstruct_formatter end end -ActiveSupport::TaggedLogging::Formatter.prepend(ActiveSupport::TaggedLogging::FormatterExtension) +module ActiveSupport::TaggedLogging::Formatter + prepend ActiveSupport::TaggedLogging::FormatterExtension +end diff --git a/lib/log_struct/param_filters.rb b/lib/log_struct/param_filters.rb index 8f52c51e..6b0b22ce 100644 --- a/lib/log_struct/param_filters.rb +++ b/lib/log_struct/param_filters.rb @@ -44,7 +44,8 @@ def should_filter_key?(key, value = nil, logstruct_field: false, path: nil, root matcher.matches?(normalized_key, value) rescue => e handle_filter_matcher_error(e, matcher.label, normalized_key) - false + # An unsuccessful filter must never expose the value it was meant to protect. + true end return true if matched return false if filters.path_matchers.empty? @@ -55,7 +56,7 @@ def should_filter_key?(key, value = nil, logstruct_field: false, path: nil, root matcher.matches?(path, value, root) rescue => e handle_filter_matcher_error(e, matcher.label, normalized_key) - false + true end end @@ -101,8 +102,8 @@ def summarize_hash(hash) { _class: Hash, - _keys_count: hash.keys.size, - _keys: hash.keys.take(10).map { |key| normalize_summary_key(StringScrubber.scrub_name(key)) } + _keys_count: hash.size, + _keys: hash.each_key.take(10).map { |key| normalize_summary_key(StringScrubber.scrub_name(key)) } } end diff --git a/lib/log_struct/string_scrubber.rb b/lib/log_struct/string_scrubber.rb index 227f629e..d8514800 100644 --- a/lib/log_struct/string_scrubber.rb +++ b/lib/log_struct/string_scrubber.rb @@ -239,7 +239,7 @@ def scrub_authorization_credentials!(string) def authorization_credentials?(scheme, credentials) return credentials.length >= 16 if scheme.casecmp?("bearer") - credentials.length >= 8 && Base64.strict_decode64(credentials).include?(":") + Base64.strict_decode64(credentials).include?(":") rescue ArgumentError false end @@ -260,7 +260,7 @@ def scrub_query_params!(string) end end - # user[password] is checked as password, written plainly or URL-encoded + # Every part of a nested name is checked: both password[] and token[value] carry secrets. sig { params(name: String, value: String).returns(T::Boolean) } def sensitive_query_param?(name, value) decoded = begin @@ -268,10 +268,11 @@ def sensitive_query_param?(name, value) rescue ArgumentError name end - key = decoded[/\[([^\[\]]*)\]\z/, 1] || decoded - return false if key.empty? - - SENSITIVE_QUERY_PARAMS.include?(key.downcase) || ParamFilters.should_filter_key?(key, value) + path = T.let([], T::Array[String]) + decoded.split(/[\[\]]/).reject(&:empty?).any? do |key| + path << key + SENSITIVE_QUERY_PARAMS.include?(key.downcase) || ParamFilters.should_filter_key?(key, value, path: path) + end end # The Luhn checksum that every card number passes diff --git a/logstruct.gemspec b/logstruct.gemspec index 8a3bf50d..5d6aa1dd 100644 --- a/logstruct.gemspec +++ b/logstruct.gemspec @@ -12,7 +12,7 @@ Gem::Specification.new do |spec| spec.description = "An opinionated and type-safe structured logging solution. " \ "Configures any Rails app to log JSON to stdout. " \ "Structured logging is automatically configured for many gems, including Sidekiq, Carrierwave, Shrine, etc. " \ - "Log messages, params, and job args are automatically filtered and scrubbed to remove any sensitive info." + "Log messages, params, and job args are filtered by sensitive keys and scrubbed for common credential and personal data patterns." spec.homepage = "https://logstruct.com" spec.license = "MIT" spec.required_ruby_version = ">= 3.3.0" diff --git a/schemas/README.md b/schemas/README.md index f85c6bde..f70ca8ec 100644 --- a/schemas/README.md +++ b/schemas/README.md @@ -29,16 +29,13 @@ This folder contains YAML schemas that declaratively define each log source and ### Base Fields -- Preferred form: -- **base.optional:** Optional boolean. When true, base fields are optional by default; use per-field `required: true` to force required. When omitted/false, fields are required by default. - - **base.fields:** Map of `LogField` names to types. -- Legacy form: - - `base_fields:` is still supported (treated as optional-by-default). Prefer `base:` going forward. +- **base.default_required:** Optional boolean, true by default. Set it to false to make base fields optional, with per-field `required: true` for exceptions. +- **base.fields:** Map of `LogField` names to types. ### Events - **events:** Map of event name → object with keys: - - **optional:** Optional boolean. When true, fields are optional by default; use per-field `required: true` to force required. When omitted/false, fields are required by default. + - **default_required:** Optional boolean, true by default. Set it to false to make event fields optional, with per-field `required: true` for exceptions. - **fields:** Map of `LogField` names to types. Field keys must be valid `LogField` enum names (validated by `log-fields.json`). - You may also declare an event with no fields by using a bare event key or `null`: @@ -52,16 +49,18 @@ You can write fields in two styles: - Required determined by `default_required` (event/base). - Example: `DurationMs: Float` -- **Object form (conditional required):** - - `FieldName: -type: Type -required: false` - - Use when some fields must remain optional even if `default_required: true`. +- **Object form:** Use when a field's requirement differs from `default_required`: + + ```yaml + Message: + type: String + required: false + ``` ### Naming Rules - Use the exact `LogField` constant name for keys (e.g., `RequestId`, `Database`, `DurationMs`, `WaitMs`). -- The generator maps these to short JSON keys via `LogField` (e.g., `RequestId` → `:request_id`). +- The generator maps these to short JSON keys via `LogField` (e.g., `RequestId` → `:req_id`). ## Units and Conventions @@ -81,26 +80,31 @@ required: false` - Serialize `Time` fields as ISO-8601 strings - Respect `default_required` and `required` for field nilability -## When To Use `optional` +## When To Use `default_required` - Use `default_required: false` when all fields in an event (or base) are optional — this removes per-field `required: false` noise. - Do NOT add `default_required: false` when you have a mix of required and optional fields — declare required fields in shorthand and optional fields with `required: false`. Examples: -- All optional fields: - - `default_required: false` - - `fields: -Filename: String -MimeType: String` - -- Mixed required/optional fields: - - Omit `optional` - - `fields: -Message: String -AhoyEvent: - type: String - required: false` +All optional fields: + +```yaml +default_required: false +fields: + Filename: String + MimeType: String +``` + +Mixed required and optional fields: + +```yaml +fields: + Message: String + AhoyEvent: + type: String + required: false +``` ## Validating and Generating diff --git a/scripts/generate_structs.rb b/scripts/generate_structs.rb index e1110e91..fd4b7a12 100755 --- a/scripts/generate_structs.rb +++ b/scripts/generate_structs.rb @@ -9,6 +9,7 @@ require "sorbet-runtime" require "fileutils" +require "tempfile" $LOAD_PATH.unshift(File.expand_path("../lib", __dir__)) require "log_struct/enums" @@ -27,7 +28,13 @@ def self.run LogStruct::Codegen::SorbetGenerator.generate_all(root) puts "Formatting generated Ruby code..." - system("bundle exec rubocop -A lib/log_struct/log > /dev/null 2>&1") + Tempfile.create("logstruct-codegen-rubocop") do |output| + unless system("bundle", "exec", "rubocop", "-A", "lib/log_struct/log", out: output, err: [:child, :out]) + output.rewind + warn(output.read) + raise "Failed to format generated Ruby log structs" + end + end puts "Generating log fields JSON..." LogStruct::Codegen::LogFieldsGenerator.generate(root) @@ -36,26 +43,22 @@ def self.run LogStruct::Codegen::TSGenerator.generate_all(root) puts "Exporting Sorbet JSON..." - begin - require "sorbet/typescript" + require "sorbet/typescript" - # Ensure the freshly generated Sorbet structs are loaded before exporting - require "log_struct/log" + # Ensure the freshly generated Sorbet structs are loaded before exporting + require "log_struct/log" - output_dir = File.join(root, "docs", "generated", "logstruct") + output_dir = File.join(root, "docs", "generated", "logstruct") - exporter = Sorbet::Typescript::Exporter.new( - enum_namespaces: ["LogStruct"], - struct_namespaces: ["LogStruct::Log"] - ) + exporter = Sorbet::Typescript::Exporter.new( + enum_namespaces: ["LogStruct"], + struct_namespaces: ["LogStruct::Log"] + ) - exporter.export( - enums_json: File.join(output_dir, "sorbet-enums.json"), - structs_json: File.join(output_dir, "sorbet-log-structs.json") - ) - rescue => e - warn("Warning exporting Sorbet JSON: #{e}") - end + exporter.export( + enums_json: File.join(output_dir, "sorbet-enums.json"), + structs_json: File.join(output_dir, "sorbet-log-structs.json") + ) end end diff --git a/test/log_struct/configuration_test.rb b/test/log_struct/configuration_test.rb index b76f2538..2b7acd1d 100644 --- a/test/log_struct/configuration_test.rb +++ b/test/log_struct/configuration_test.rb @@ -268,6 +268,32 @@ def test_rails_filter_blocks_with_three_arguments refute ParamFilters.should_filter_key?("name", "Ada") end + def test_failing_rails_filter_blocks_filter_the_value + filters = [ + ->(key, _value) { + raise "filter failed" if key == "private_data" + nil + }, + ->(key, _value, _root) { + raise "filter failed" if key == "private_data" + nil + } + ] + filters.each do |filter| + LogStruct.config.filters.filter_matchers = [] + LogStruct.config.filters.path_matchers = [] + with_rails_filter_parameters([filter]) { LogStruct.merge_rails_filter_parameters! } + reported = [] + line = LogStruct.stub(:handle_exception, ->(error, **) { reported << error.message }) do + Formatter.new.call(:info, Time.now, nil, {private_data: "synthetic-secret", public_data: "visible"}) + end + + assert_equal ["filter failed"], reported + assert_not_includes line, "synthetic-secret" + assert_equal "visible", JSON.parse(line)["public_data"] + end + end + def test_rails_filter_blocks_with_three_arguments_get_the_parameters # Rails gives the block the whole params Hash, with indifferent access number_filter = ->(key, _value, params) { key == "number" && params[:kind] == "card" } @@ -301,6 +327,15 @@ def test_rails_dotted_filters_match_nested_keys_by_their_path refute ParamFilters.should_filter_key?("nickname", "x") end + def test_rails_dotted_filters_match_nested_query_parameters + with_rails_filter_parameters(["profile.nickname", /\Ateam\.motto\z/]) do + LogStruct.merge_rails_filter_parameters! + end + + assert_equal "/save?profile[nickname][]=[FILTERED]&nickname=visible&team[motto]=[FILTERED]", + StringScrubber.scrub("/save?profile[nickname][]=hidden&nickname=visible&team[motto]=hidden") + end + # A Hash that counts its conversions to indifferent access class CountedHash < Hash class << self diff --git a/test/log_struct/formatter_test.rb b/test/log_struct/formatter_test.rb index ab0ef6fe..e1987ab8 100644 --- a/test/log_struct/formatter_test.rb +++ b/test/log_struct/formatter_test.rb @@ -276,6 +276,17 @@ def test_summarizes_each_type_past_the_depth_limit assert_nil @formatter.process_values(nil, recursion_depth: too_deep) end + def test_summarizes_symbols_past_the_depth_limit + deep = :"synthetic@example.com" + Formatter::MAX_RECURSION_DEPTH.times { deep = [deep] } + + log_line = @formatter.call(@severity, @time, @progname, {data: deep}) + + assert_not_includes log_line, "synthetic@example.com" + assert_includes log_line, '"_class":"Symbol"' + JSON.parse(log_line) + end + def test_logs_circular_hashes_without_raising circular = {name: "loop"} circular[:self] = circular @@ -295,8 +306,8 @@ def test_logs_hashes_with_several_back_references_once ctx = JSON.parse(log_line).fetch("ctx") assert_equal "loop", ctx["name"] - assert_equal "loop", ctx.dig("first", "name") - assert_equal({"_class" => "Hash", "_keys_count" => 3}, ctx.dig("first", "first", "_filtered")) + assert_equal({"_class" => "Hash", "_keys_count" => 3}, ctx.dig("first", "_filtered")) + assert_equal ctx["first"], ctx["second"] assert_operator log_line.bytesize, :<, 1000 end @@ -407,15 +418,15 @@ def test_log_value_to_hash_with_string end def test_log_value_to_hash_with_hash - # Test hash conversion (including string keys) - result = @formatter.log_value_to_hash({ - "string_key" => "value", - :symbol_key => "symbol_value" - }, - time: @time) + input = { + "string_field" => "value", + :symbol_field => "symbol_value" + } + result = JSON.parse(@formatter.call(@severity, @time, @progname, input)) - assert_equal "value", result[:string_key] - assert_equal "symbol_value", result[:symbol_key] + assert_equal "value", result["string_field"] + assert_equal "symbol_value", result["symbol_field"] + assert_equal ["string_field", :symbol_field], input.keys end def test_log_value_to_hash_with_struct @@ -595,6 +606,38 @@ def test_writes_the_first_keys_of_a_large_hash assert_equal({"k1" => 1, "k2" => 2, "k3" => 3, "_more_keys" => 7}, result["data"]) end + class KeyProbe + attr_reader :visits + + def initialize + @visits = 0 + end + + def to_sym + @visits += 1 + :unvisited + end + end + + def test_does_not_traverse_values_outside_the_size_limits + key = KeyProbe.new + skipped = {key => "hidden"} + inputs = [ + {items: Array.new(LogStruct.config.limits.max_array_items, "visible") + [skipped]}, + {data: (1..LogStruct.config.limits.max_hash_keys).to_h { |i| ["k#{i}", i] }.merge("ignored" => skipped)}, + {password: {nested: skipped}} + ] + + inputs.each do |input| + line = @formatter.call(@severity, @time, @progname, input) + + assert_not_includes line, "hidden" + JSON.parse(line) + end + + assert_equal 0, key.visits + end + def test_writes_the_first_lines_of_a_backtrace_like_array result = JSON.parse(@formatter.call(@severity, @time, @progname, {msg: "Trace", lines: ["a:0"] * 150})) diff --git a/test/log_struct/param_filters_test.rb b/test/log_struct/param_filters_test.rb index 19f72d80..4cd07e4c 100644 --- a/test/log_struct/param_filters_test.rb +++ b/test/log_struct/param_filters_test.rb @@ -25,6 +25,91 @@ class ParamFiltersTest < ActiveSupport::TestCase refute ParamFilters.should_include_string_hash?(:password) end + test "a failing key matcher filters the value when its error is handled" do + LogStruct.config.filters.filter_matchers << ConfigStruct::FilterMatcher.new( + callable: ->(key, _value) { + raise "matcher failed" if key == "private_data" + false + }, + label: "failing matcher" + ) + + assert_failing_matcher_filters_value + end + + test "a failing path matcher filters the value when its error is handled" do + LogStruct.config.filters.path_matchers << ConfigStruct::PathFilterMatcher.new( + callable: ->(path, _value, _root) { + raise "matcher failed" if path.last == "private_data" + false + }, + label: "failing matcher" + ) + + assert_failing_matcher_filters_value + end + + private def assert_failing_matcher_filters_value + reported = [] + line = LogStruct.stub(:handle_exception, ->(error, **) { reported << error.message }) do + Formatter.new.call(:info, Time.now, nil, {private_data: "synthetic-secret", public_data: "visible"}) + end + + assert_equal ["matcher failed"], reported + assert_not_includes line, "synthetic-secret" + assert_equal({"_filtered" => {"_class" => "String"}}, JSON.parse(line)["private_data"]) + assert_equal "visible", JSON.parse(line)["public_data"] + end + + test "a filter that fails on every key does not keep logging its own failures" do + LogStruct.config.error_handling_modes.logstruct_errors = ErrorHandlingMode::Log + LogStruct.config.filters.filter_matchers = [ConfigStruct::FilterMatcher.new( + callable: ->(_key, _value) { raise "matcher failed" }, label: "failing matcher" + )] + pending = [] + LogStruct.stub(:error, ->(entry) { pending << entry }) do + formatter = Formatter.new + line = formatter.call(:info, Time.now, nil, {private_data: "synthetic-secret"}) + + assert_not_includes line, "synthetic-secret" + refute_empty pending + errors = pending.dup + pending.clear + errors.each { |error| JSON.parse(formatter.call(:error, Time.now, nil, error)) } + + assert_empty pending, "Formatting an internal error must not enqueue another internal error" + end + end + + test "a failing filter does not recursively report failures in its error context" do + LogStruct.config.error_handling_modes.logstruct_errors = ErrorHandlingMode::Report + attempts = 0 + LogStruct.config.filters.filter_matchers = [ConfigStruct::FilterMatcher.new( + callable: ->(_key, _value) { + attempts += 1 + # Bound the regression so a broken implementation fails without overflowing the stack. + raise "matcher failed" if attempts <= 10 + true + }, + label: "failing matcher" + )] + reported = T.let([], T::Array[T.untyped]) + LogStruct.config.error_reporting_handler = ->(error, context, _source) { reported << [error.message, context] } + + LogStruct.stub(:error, ->(_entry) {}) do + line = Formatter.new.call(:info, Time.now, nil, {private_data: "synthetic-secret"}) + + assert_not_includes line, "synthetic-secret" + end + + assert_equal 1, reported.size + report = T.must(reported.first) + + assert_equal "matcher failed", report.first + assert_equal({_filtered: {_class: String}}, report.last[:matcher]) + assert_nil Thread.current[:logstruct_formatting_internal_error] + end + test "summarize_string includes hash when requested" do s = ParamFilters.summarize_string("abc@ex.com", true) diff --git a/test/log_struct/string_scrubber_test.rb b/test/log_struct/string_scrubber_test.rb index 351a5805..02dc2553 100644 --- a/test/log_struct/string_scrubber_test.rb +++ b/test/log_struct/string_scrubber_test.rb @@ -102,6 +102,12 @@ def test_scrub_url_passwords assert_includes result, "[PASSWORD]" end + def test_scrub_short_basic_credentials + ["a:b", ":x", "x:", ":"].each do |credentials| + assert_equal "Basic [FILTERED]", StringScrubber.scrub("Basic #{Base64.strict_encode64(credentials)}") + end + end + def test_scrub_credit_card_numbers # Test with a 16-digit card number input = "Card: 4111111111111111" @@ -177,6 +183,13 @@ def test_query_params_can_be_left_alone assert_equal "/reset?token=abc123", StringScrubber.scrub("/reset?token=abc123") end + def test_scrub_sensitive_query_params_in_arrays_and_nested_hashes + %w[password[] token[value] user[password][] user%5Bpassword%5D%5B%5D].each do |name| + assert_equal "/login?#{name}=[FILTERED]&page=2", StringScrubber.scrub("/login?#{name}=synthetic-secret&page=2") + end + assert_equal "/search?tags[]=ruby", StringScrubber.scrub("/search?tags[]=ruby") + end + def test_scrub_name_skips_identifiers assert_equal :user_id, StringScrubber.scrub_name(:user_id) assert_equal "createdAt", StringScrubber.scrub_name("createdAt") diff --git a/test/workflows/generation_test.rb b/test/workflows/generation_test.rb new file mode 100644 index 00000000..f3487b36 --- /dev/null +++ b/test/workflows/generation_test.rb @@ -0,0 +1,49 @@ +# typed: true +# frozen_string_literal: true + +require "test_helper" +require "open3" + +module LogStruct + class GenerationTest < ActiveSupport::TestCase + # Skip writes in the child process so failure checks cannot change generated files. + SETUP = <<~RUBY + require "bundler/setup" + require "sorbet-runtime" + $LOAD_PATH.unshift(File.expand_path("lib")) + require "log_struct/enums" + require_relative "tools/codegen/sorbet_generator" + require_relative "tools/codegen/ts_generator" + require_relative "tools/codegen/log_fields_generator" + LogStruct::Codegen::SorbetGenerator.define_singleton_method(:generate_all) { |root| } + LogStruct::Codegen::TSGenerator.define_singleton_method(:generate_all) { |root| } + LogStruct::Codegen::LogFieldsGenerator.define_singleton_method(:generate) { |root| } + RUBY + + test "a failed formatter stops generation" do + output, status = run_generator("Kernel.define_method(:system) { |*args| false }") + + refute_predicate status, :success?, output + assert_includes output, "Failed to format generated Ruby log structs" + assert_not_includes output, "Exporting Sorbet JSON" + end + + test "a failed JSON export fails generation" do + output, status = run_generator(<<~RUBY) + Kernel.define_method(:system) { |*args| true } + require "sorbet/typescript" + Sorbet::Typescript::Exporter.define_method(:export) { |**args| raise "intentional export failure" } + RUBY + + refute_predicate status, :success?, output + assert_includes output, "intentional export failure" + end + + private + + def run_generator(injection) + script = SETUP + injection + "\nload 'scripts/generate_structs.rb'\n" + Open3.capture2e(RbConfig.ruby, "-e", script, chdir: File.expand_path("../..", __dir__)) + end + end +end