| Commit message (Collapse) | Author | Age | Files | Lines |
| |
|
|
|
|
|
| |
This reverts commit 3420a14590c0e6915d8b6c242887f74adb4120f9, reversing
changes made to afb66a5a598ce4ac74ad84b125a5abf046dcf5aa.
|
| |
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
`test_cache_is_available_when_using_a_not_connected_connection` is
always failed if running only the test since #29609.
```
% ARCONN=mysql2 be ruby -w -Itest test/cases/query_cache_test.rb -n test_cache_is_available_when_using_a_not_connected_connection
Using mysql2
Run options: -n test_cache_is_available_when_using_a_not_connected_connection --seed 15043
F
Finished in 0.070519s, 14.1806 runs/s, 28.3612 assertions/s.
1) Failure:
QueryCacheTest#test_cache_is_available_when_using_a_not_connected_connection [test/cases/query_cache_test.rb:336]:
2 instead of 1 queries were executed.
Queries:
SELECT `tasks`.* FROM `tasks` WHERE `tasks`.`id` = ? LIMIT ?
SET NAMES utf8 COLLATE utf8_unicode_ci, @@SESSION.sql_mode = CONCAT(CONCAT(@@sql_mode, ',STRICT_ALL_TABLES'), ',NO_AUTO_VALUE_ON_ZERO'), @@SESSION.sql_auto_is_null = 0, @@SESSION.wait_timeout = 2147483.
Expected: 1
Actual: 2
1 runs, 2 assertions, 1 failures, 0 errors, 0 skips
```
This failure is due to `LogSubscriber` will use not connected
`ActiveRecord::Base.connection` even if `Task.connection` is connected.
I fixed to always pass `type_casted_binds` to log subscriber to avoid
the issue.
|
|
|
|
| |
Follow up of #27939.
|
| |
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
Query cache doesn't type cast bind parameters since it isn't
actually querying the database, so it can't pass those values in. Type
casting in the query cache method would cause the values to be type cast
twice in the case that there is a cache miss (since the methods it calls
will type cast *again*). If logging is disabled, then adding the type
cast code to the query cache method will needlessly typecast the values
(since the only reason those values are type cast is for display in the
logs).
Fixes #26828.
|
| |
|
|\
| |
| | |
Fix database runtimes on production log
|
| |
| |
| |
| |
| |
| |
| |
| | |
Rails default production configuration establishes "info" as log level.
Due to the changes included on commit
191facc857bb4fb52078fb544c6bc1613a81cc80, db runtimes were not being
collected if the log level was different than "debug", and 0.0 ms was
the runtime reported on production logs.
|
| | |
|
| |
| |
| |
| |
| | |
This was used to switch the output colour between log lines, but now the
output colour is based on the type of statement being logged instead.
|
| | |
|
| | |
|
| |
| |
| |
| | |
Address to https://github.com/rails/rails/commit/5a302bf553af0e6fedfc63299fc5cd6e79599ef3#commitcomment-18288388.
|
| |
| |
| |
| | |
Fixes #22398.
|
|/
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
If an attribute was of the binary type, and also was a Hash, it would
previously not be logged, and instead raise an error saying that
`bytesize` was not defined for the `attribute.value` (a `Hash`).
Now, as is done on 4-2-stable, the attribute's database value is
`bytesize`d, and then logged out to the terminal.
Reproduction script:
```ruby
require 'active_record'
require 'minitest/autorun'
require 'logger'
ActiveRecord::Base.establish_connection(adapter: 'sqlite3', database: ':memory:')
ActiveRecord::Base.logger = Logger.new(STDOUT)
ActiveRecord::Schema.define do
create_table :posts, force: true do |t|
t.binary :preferences
end
end
class Post < ActiveRecord::Base
serialize :preferences
end
class BugTest < Minitest::Test
def test_24955
Post.create!(preferences: {a: 1})
assert_equal 1, Post.count
end
end
```
|
| |
|
|\
| |
| |
| | |
Fix and Improve sql logging coloration in `ActiveRecord::LogSubscriber`.
|
| |
| |
| |
| |
| |
| |
| |
| |
| |
| |
| |
| |
| |
| |
| | |
- CR feedback from @egilburg
Additionally
- Move logic for colorizing the payload name into a separate method
- Make some `ActiveRecord::LogSubscriber` instance methods private for clarity:
- `colorize_payload_name`
- `sql_color`
- `logger`
- Improve Changelog Documentation
GH #20885
|
|/
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
- Improves coloring for statements like:
# Become WHITE
SELECT * FROM (
SELECT * FROM mytable FOR UPDATE
) ss WHERE col1 = 5;
LOCK TABLE table_name IN ACCESS EXCLUSIVE MODE;
# Becomes RED
ROLLBACK
- Reinstates the coloration of the `payload[:name]`.
Instead of simple alternating colors, adds meaning:
- `MAGENTA` for `"SQL"` or `blank?` payload names
- `CYAN` for Model Load/Exists
- Introduces specs for sql coloration.
- Introduces specs for payload name coloration.
GH#20885
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
This new coloration approach makes it easier to scan the rails console
for specific types of activity with more fine-grained visual cues.
Virtual terminal ANSI color escape codes are used when displaying SQL
statements in the rails console. The former implementation alternates
line prefix information (including the statement name and execution
latency) between CYAN and MAGENTA. This visually differentiates any SQL
statements in the log and is useful for quickly scanning for database
activity.
While a great idea and a solid foundation, alternating between just two
colors on an even/odd basis (much like striping an HTML table) can be
improved upon.
This patch replaces the even/odd striping with a more comprehensive
scheme that applies coloration based on the type of statement being
run. Every statement logged has its prefix (name and latency) colored
white (as the statement body was previously). The statement body is now
colored according to the nature of the statement:
- INSERT statements are GREEN (symbolic of creation or genesis)
- SELECT statements are BLUE (typically used for informational
displays, as SELECT statements do not normally have side-effects)
- DELETE statements are RED (commonly used to indicate the danger of
a destructive action)
- UPDATE statements are YELLOW (it's like a less extreme RED :P)
- TRANSACTION statements are CYAN (arbitrary)
- and any other statements are MAGENTA (again, arbitrary)
|
|
|
|
|
|
|
|
|
| |
`sql_runtime` was getting invoked even when the logger was set to fatal.
This ensures that does not happen by checking that the logger is set to
info level before logging the view runtime.
This reduces the number of times `sql_runtime` is called for integration
tests with a fatal logger from 6 to 2.
|
|
|
|
|
|
|
|
| |
`bound_attributes` is now used universally across the board, removing
the need for the conversion layer. These changes are mostly mechanical,
with the exception of the log subscriber. Additional, we had to
implement `hash` on the attribute objects, so they could be used as a
key for query caching.
|
|
|
|
|
|
| |
There's very little value in logging "<NULL binary data>" instead of
just "nil". I'd like to remove the column from the equation entirely,
and this case is preventing us from doing so.
|
|
|
|
| |
The case where the value is present is more common
|
| |
|
|
|
|
|
| |
This is a follow up to: 97f0d9a0dd12e7ad634815eecfeff866f64aad92
This change is also related to: df0edafac9eb47cd971970a9e7b13a3eaddf214e
|
|
|
|
| |
Also renaming ivar @odd_or_even to @odd
|
|
|
|
|
|
|
|
|
|
|
|
| |
If I have a query that produces sql
`WHERE "users"."name" = 'a b'` then in the log all the
whitespace is being squeezed. So the sql that is printed in the
log is `WHERE "users"."name" = 'a b'`.
This can be confusing. This commit fixes it by ensuring that
whitespace is not squeezed.
fixes #10982
|
|
|
|
|
|
|
|
|
|
| |
Registries have class-level accessors to write clean code, let's
use them. This makes style uniform also with existing usage in
ScopeRegistry and InstrumentationRegistry.
If performance of the method_missing callback was ever considered to
be a concern, then we should stop using it altogether and probably
remove the callback. But while we have the feature we should use it.
|
| |
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
Some tests were raising the following error:
Could not log "sql.active_record" event. NoMethodError: undefined method
`type' for nil:NilClass`
Due to the way binds were being logged, the column info was considered
always present, but that is not true for some of the tests listed in the
issue.
Closes #8806.
|
|
|
|
|
|
|
| |
Mysql2 doesn't support binds, which means no binds payload is set when
logging, so the logic to render binary data differently here doesn't work.
Introduced in 99d142a9375f9ba1960863b3cc745265aa9a14df.
|
|
|
|
| |
They tend to be large and not very useful in the log.
|
|
|
|
| |
performing an operations.
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
| |
This commit vastly reduces the impact of auto
explain logging when enabled, while keeping
a negligible cost when disabled.
The first implementation was based on the idea
of subscribing to "sql.active_record" when
needed, and unsubscribing once done. This is
the idea behind AR::Relation#explain. Subscribe,
collect, unsubscribe.
But with the current implementation of notifications
unsubscribing is costly, because it wipes an internal
cache and that puts a penalty on the next event.
So we are switching to an approach where a long-running
subscriber is listening. Instead of collecting the
queries with a closure in a dedicated subscriber, now
we setup a thread local.
If the feature is disabled by setting the threshold
to nil, the subscriber will call a method that does
nothing. That's totally cheap.
|
|
|
|
| |
the messages nicely with colors (FIXME: Can someone look into why the test is not working?)
|
| |
|
| |
|
| |
|
| |
|
| |
|
| |
|
| |
|
|
|
|
|
|
| |
* AS::Notifications#instrument should not measure anything, it is not its responsibility;
* Adding another argument to AS::Notifications#instrument API needs to be properly discussed;
|
| |
|
| |
|
| |
|
| |
|