Return from SQL query to application code?

Question

Is there a way to find which line of code the MySQL statement generated in the Rails development log?

To do some performance optimization, I would like to find which part of my application creates which MySQL queries. When I look at my journal, I see that around each request on the web page there are request requests, and I need to find out where they came from.

I am thinking of adding some variables, such as ____FILE____ and ____LINE____ to the output of the log.

Is it possible?

Answer 1

https://github.com/lightyear/sql-logging gives you a return line for each SQL query plus a bunch of useful statistics.

Answer 2

You have several options. None of these options will definitely give you backtrace the same way you get Ruby backtrace on errors, but they will provide you with the tools and information you need to track exactly where your SQL queries are coming up.

• Your typical Rails log entry would look something like this:

   Started GET "/login" for 127.0.0.1 at Thu Sep 27 18:59:08 -0500 2012 Processing by PublicController#index as HTML (40.9ms) SELECT COUNT(*) FROM "studies" (49.6ms) SELECT COUNT(DISTINCT "activities"."whodiddit") FROM "activities" (35.3ms) SELECT COUNT(*) FROM "involvements" 

  I assume your hundreds of SQL queries are happening here?

   Rendered partials/_faq.haml (6.1ms) Rendered public/index.html.haml within layouts/public (114.3ms) Completed 200 OK in 595ms (Views: 276.7ms | ActiveRecord: 151.6ms) 

  So, at the top, you got the HTTP verb GET and the route ( /login in my example) and the node from which it came. After that, Rails tells you which controller + action is starting.

  Note. If you see a line starting with Rendered... that you render. Any SQL queries that appear after rendering indicate that SQL queries are triggered in your view (for example, outside your controller). Just something to think about. Depending on what code you are invoking, the actual lines that run your SQL queries may be buried in helpers, models, or elsewhere that invokes the view code.

   Processing by PublicController#index as HTML 

  The as HTML bit at the end tells you in what format the request was requested, and therefore what kind / format is likely to be used in the response.

  So, what this tells you basically is that SQL queries were called either as part of the index action in the PublicController , or one of the views that this controller displays as a result of this action is triggered.

• If there is too much to parse, you use debugger commands to stop output at different points and let you check what is happening. Read more about the debugger here .

• You can use Rails.logger.info "My info message" or Rails.logger.error "My error message" (depending on whether you want this in the default log or in the error log, etc.) to output data directly in the application log.