Skip to content

Conversation

gmcgibbon
Copy link
Member

Motivation / Background

This Pull Request has been created because #52297 isn't working exactly the way I expected.

Previously, we would sometimes log nil when verbose logs are disabled, and dispatch route level source locations could not be found.

Detail

This Pull Request changes mostly dispatch code to record some source location in redirect endpoints when needed. This allows this feature to work in environments other than development, if needed, instead of depending on the other route source locations feature.

This adds an additional parameter to redirect.action_dispatch which may not be desirable. We can instead hack the caller trace to include the source location or use route source locations. Open to feedback on this, but I prefer to keep things simple here with an event parameter.

Checklist

Before submitting the PR make sure the following are checked:

  • This Pull Request is related to one change. Unrelated changes should be opened in separate PRs.
  • Commit message has a detailed description of what changed and why. If this PR fixes a related issue include it in the commit message. Ex: [Fix #issue-number]
  • Tests are added or updated if you fix a bug or add a feature.
  • CHANGELOG files are updated for the changed libraries if there is a behavior change or additional feature. Minor bug fixes and documentation changes should not be included.

Previously, we would sometimes log nil when verbose logs are disabled,
and dispatch route level source locations could not be found.
@gmcgibbon gmcgibbon force-pushed the fix_verbose_redirect_logs branch from c289c0a to afe6924 Compare October 12, 2025 14:56
@rafaelfranca rafaelfranca merged commit 25ada06 into rails:main Oct 14, 2025
3 checks passed
@rafaelfranca rafaelfranca deleted the fix_verbose_redirect_logs branch October 14, 2025 18:12

### Notable changes

* Redirects are now verbose in development for new Rails apps. To enable it in an existing app, add `config.action_dispatch.verbose_redirect_logs = true` to your `config/development.rb` file.
Copy link
Contributor

Choose a reason for hiding this comment

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

Thanks!

yahonda added a commit to yahonda/rails that referenced this pull request Oct 15, 2025
This commit addresses the following failure with Ruby 3.5.0.dev
since `source_location` includes start_column, end_line, end_column.

Follow up rails#55889

- Fixed by this commit
```ruby
$ ruby -v
ruby 3.5.0dev (2025-10-14T22:26:08Z master df5d63cfa2) +PRISM [x86_64-linux]
$ bin/test test/controller/log_subscriber_test.rb:331
Running 36 tests in a single process (parallelization threshold is 50)
Run options: --seed 1476

F

Failure:
ACLogSubscriberTest#test_verbose_redirect_logs [test/controller/log_subscriber_test.rb:331]:
Expected /\u21B3 \/home\/yahonda\/src\/github.com\/rails\/rails\/actionpack\/test\/controller\/log_subscriber_test.rb:8/ to match "↳ /home/yahonda/src/github.com/rails/rails/actionpack/test/controller/log_subscriber_test.rb:28:in 'Another::LogSubscribersController#redirector'".

bin/test test/controller/log_subscriber_test.rb:320

Finished in 0.063581s, 15.7279 runs/s, 47.1836 assertions/s.
1 runs, 3 assertions, 1 failures, 0 errors, 0 skips
$
```

- Additional information

- Modified to show the entire source_location
```
$ git diff -- test/controller/log_subscriber_test.rb
diff --git a/actionpack/test/controller/log_subscriber_test.rb b/actionpack/test/controller/log_subscriber_test.rb
index 0b6e5b0..e19848b769 100644
--- a/actionpack/test/controller/log_subscriber_test.rb
+++ b/actionpack/test/controller/log_subscriber_test.rb
@@ -318,6 +318,7 @@ def test_filter_redirect_bad_uri
   end

   def test_verbose_redirect_logs
+    pp Another::LogSubscribersController.instance_method(:redirector).source_location
     line = Another::LogSubscribersController.instance_method(:redirector).source_location.last + 1
     old_cleaner = ActionController::LogSubscriber.backtrace_cleaner
     ActionController::LogSubscriber.backtrace_cleaner = ActionController::LogSubscriber.backtrace_cleaner.dup
$
```

- Ruby 3.5.0dev source_location returns an array of 5 elements.
```
$ ruby -v
ruby 3.5.0dev (2025-10-14T22:26:08Z master df5d63cfa2) +PRISM [x86_64-linux]
yahonda@myubuntu:~/src/github.com/rails/rails/actionpack$ bin/test test/controller/log_subscriber_test.rb:331
Running 36 tests in a single process (parallelization threshold is 50)
Run options: --seed 37374

["/home/yahonda/src/github.com/rails/rails/actionpack/test/controller/log_subscriber_test.rb", 27, 4, 29, 7]
F

Failure:
ACLogSubscriberTest#test_verbose_redirect_logs [test/controller/log_subscriber_test.rb:332]:
Expected /\u21B3 \/home\/yahonda\/src\/github.com\/rails\/rails\/actionpack\/test\/controller\/log_subscriber_test.rb:8/ to match "↳ /home/yahonda/src/github.com/rails/rails/actionpack/test/controller/log_subscriber_test.rb:28:in 'Another::LogSubscribersController#redirector'".

bin/test test/controller/log_subscriber_test.rb:320

Finished in 0.067459s, 14.8237 runs/s, 44.4712 assertions/s.
1 runs, 3 assertions, 1 failures, 0 errors, 0 skips
$
```

- Ruby 3.4.7 source_location returns an array of 2 elements.
```
$ ruby -v
ruby 3.4.7 (2025-10-08 revision 7a5688e2a2) +PRISM [x86_64-linux]
$ bin/test test/controller/log_subscriber_test.rb:331
Running 36 tests in a single process (parallelization threshold is 50)
Run options: --seed 6959

["/home/yahonda/src/github.com/rails/rails/actionpack/test/controller/log_subscriber_test.rb", 27]
.

Finished in 0.067913s, 14.7247 runs/s, 44.1740 assertions/s.
1 runs, 3 assertions, 0 failures, 0 errors, 0 skips
$
```

https://bugs.ruby-lang.org/issues/6012
ruby/ruby#12539
yahonda added a commit to yahonda/rails that referenced this pull request Oct 15, 2025
This commit addresses the following failure with Ruby 3.5.0.dev
since `source_location` includes start_column, end_line, end_column.

Follow up rails#55889

- Fixed by this commit
```ruby
$ ruby -v
ruby 3.5.0dev (2025-10-14T22:26:08Z master df5d63cfa2) +PRISM [x86_64-linux]
$ bin/test test/controller/log_subscriber_test.rb:331
Running 36 tests in a single process (parallelization threshold is 50)
Run options: --seed 1476

F

Failure:
ACLogSubscriberTest#test_verbose_redirect_logs [test/controller/log_subscriber_test.rb:331]:
Expected /\u21B3 \/home\/yahonda\/src\/github.com\/rails\/rails\/actionpack\/test\/controller\/log_subscriber_test.rb:8/ to match "↳ /home/yahonda/src/github.com/rails/rails/actionpack/test/controller/log_subscriber_test.rb:28:in 'Another::LogSubscribersController#redirector'".

bin/test test/controller/log_subscriber_test.rb:320

Finished in 0.063581s, 15.7279 runs/s, 47.1836 assertions/s.
1 runs, 3 assertions, 1 failures, 0 errors, 0 skips
$
```

- Additional information

- Modified to show the entire source_location
```
$ git diff -- test/controller/log_subscriber_test.rb
diff --git a/actionpack/test/controller/log_subscriber_test.rb b/actionpack/test/controller/log_subscriber_test.rb
index 0b6e5b0..e19848b769 100644
--- a/actionpack/test/controller/log_subscriber_test.rb
+++ b/actionpack/test/controller/log_subscriber_test.rb
@@ -318,6 +318,7 @@ def test_filter_redirect_bad_uri
   end

   def test_verbose_redirect_logs
+    pp Another::LogSubscribersController.instance_method(:redirector).source_location
     line = Another::LogSubscribersController.instance_method(:redirector).source_location.last + 1
     old_cleaner = ActionController::LogSubscriber.backtrace_cleaner
     ActionController::LogSubscriber.backtrace_cleaner = ActionController::LogSubscriber.backtrace_cleaner.dup
$
```

- Ruby 3.5.0dev source_location returns an array of 5 elements.
```
$ ruby -v
ruby 3.5.0dev (2025-10-14T22:26:08Z master df5d63cfa2) +PRISM [x86_64-linux]
$ bin/test test/controller/log_subscriber_test.rb:331
Running 36 tests in a single process (parallelization threshold is 50)
Run options: --seed 37374

["/home/yahonda/src/github.com/rails/rails/actionpack/test/controller/log_subscriber_test.rb", 27, 4, 29, 7]
F

Failure:
ACLogSubscriberTest#test_verbose_redirect_logs [test/controller/log_subscriber_test.rb:332]:
Expected /\u21B3 \/home\/yahonda\/src\/github.com\/rails\/rails\/actionpack\/test\/controller\/log_subscriber_test.rb:8/ to match "↳ /home/yahonda/src/github.com/rails/rails/actionpack/test/controller/log_subscriber_test.rb:28:in 'Another::LogSubscribersController#redirector'".

bin/test test/controller/log_subscriber_test.rb:320

Finished in 0.067459s, 14.8237 runs/s, 44.4712 assertions/s.
1 runs, 3 assertions, 1 failures, 0 errors, 0 skips
$
```

- Ruby 3.4.7 source_location returns an array of 2 elements.
```
$ ruby -v
ruby 3.4.7 (2025-10-08 revision 7a5688e2a2) +PRISM [x86_64-linux]
$ bin/test test/controller/log_subscriber_test.rb:331
Running 36 tests in a single process (parallelization threshold is 50)
Run options: --seed 6959

["/home/yahonda/src/github.com/rails/rails/actionpack/test/controller/log_subscriber_test.rb", 27]
.

Finished in 0.067913s, 14.7247 runs/s, 44.1740 assertions/s.
1 runs, 3 assertions, 0 failures, 0 errors, 0 skips
$
```

https://bugs.ruby-lang.org/issues/6012
ruby/ruby#12539
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants