This project is archived and is in readonly mode.
ActiveRecord splits log records across multiple lines
Reported by Sam Ruby | October 18th, 2009 @ 02:14 AM | in 3.0.2
Given the following statement:
order = Order.find(:first)
Rails 2.3.4 produces the following log entry:
Order Load (1.5ms) SELECT * FROM "orders" LIMIT 1
Now that ARel has landed, Rails 3.0pre produces the following log entries:
Order Load (1.1ms) SELECT *
FROM "orders"
LIMIT 1
This clearly isn't a bug, but arguably is a fit and finish item, as putting log entries on one line would make it easier to scan. At a minimum, subsequent lines should be indented or otherwise easily identified as a continuation.
Comments and changes to this ticket
-
Jeremy Kemper November 24th, 2009 @ 05:39 PM
- Assigned user changed from Yehuda Katz (wycats) to Jeremy Kemper
- State changed from new to open
- Milestone cleared.
Yup - one line is preferable.
-
Sam Ruby December 9th, 2009 @ 03:22 PM
It has since gotten even less usable, as ANSI screen control characters are now included in the log itself.
*[4;36;1msql (0.0ms)*[0m *[0;1mSELECT * FROM "products" ORDER BY title*[0m
A few well placed gsubs could clean this right up.
line.gsub! "\n", ' ' line.gsub! /\x1b\[\d(;\d+)*m/, ''
-
Ben Marini January 17th, 2010 @ 09:35 PM
You can solve the ANSI control characters issue with
config.colorize_logging = false
.As for the multiline SQL, I would almost say it's an easy fix in ActiveRecord::Railties::Subscriber:
- sql = event.payload[:sql].squeeze(' ') + sql = event.payload[:sql].gsub(/\s+/, ' ').strip
The only problem with this (and with the current use of #squeeze) is that there is the possibility you'll inadvertently change the SQL statement itself! For instance, queries with intentional extra spaces in a condition:
"SELECT * FROM table_a WHERE col1 LIKE 'something something else'" # Note the double space in LIKE clause
This is probably a rare case, but I think it's pretty important for the logger to log the same SQL that was presented to the connection adapter. Maybe the white space can be trimmed ahead of time, before it reaches the logger?
-
Daniel Guettler January 18th, 2010 @ 04:28 AM
I cannot reproduce this; logs look fine to me using the latest version of rails. I tried both sqlite and mysql.
Migrating to CreateOrders (20100118042221) SQL (0.2ms) select sqlite_version(*) SQL (0.6ms) CREATE TABLE "orders" ("id" INTEGER PRIMARY KEY AUTOINCREMENT NOT NULL, "name" varchar(255), "created_at" datetime, "updated_at" datetime) Order Load (0.3ms) SELECT "orders"."id", "orders"."name", "orders"."created_at", "orders"."updated_at" FROM "orders" LIMIT 1 Migrating to CreateOrders (20100118042221) SQL (95.3ms) CREATE TABLE `schema_migrations` (`version` varchar(255) NOT NULL) ENGINE=InnoDB SQL (47.8ms) CREATE UNIQUE INDEX `unique_schema_migrations` ON `schema_migrations` (`version`) SQL (0.3ms) SET SQL_AUTO_IS_NULL=0 orders Columns (74.2ms) SHOW FIELDS FROM `orders` Order Load (0.3ms) SELECT `orders`.`id`, `orders`.`name`, `orders`.`created_at`, `orders`.`updated_at` FROM `orders` LIMIT 1
Am I missing something here?
-
Sam Ruby February 3rd, 2010 @ 12:57 PM
- State changed from open to resolved
-
Jeremy Kemper October 15th, 2010 @ 11:01 PM
- Milestone set to 3.0.2
- Importance changed from to Low
Create your profile
Help contribute to this project by taking a few moments to create your personal profile. Create your profile »
<h2 style="font-size: 14px">Tickets have moved to Github</h2>
The new ticket tracker is available at <a href="https://github.com/rails/rails/issues">https://github.com/rails/rails/issues</a>