Ottimizzare Ruby On Rails (parte 3): Il database

19 11 2007

Il primo passaggio che consiglio, quando si inizia il lavoro di ottimizzazione sul database è quello di fornirsi di uno strumento in grado di evidenziare i punti critici.

Partendo dall’accesso al database, lo strumento migliore che ho trovato fin’ora è Query Trace, una plugin che permette di evidenziare nel log dove effettivamente vengono effettuate le chiamate al database e soprattutto, se all’interno di uno stesso processo (ad esempio il rendering di una pagina) vengono effettuate in ripetizione le stesse query.

Vediamo come funziona con degli esempi pratici, che utilizzerò anche per provare a fare qualche ottimizzazione sulle chiamate al database.

Prima di tutto ho creato un’applicazione Rails minimale, con due modelli, articolo e autore. Ogni articolo ha un titolo ed un autore, ogni autore ha un nome. Come si vede, gli oggetti servono solo proprio per tenere in piedi l’esempio.

Articolo:

class Article < ActiveRecord::Base
  belongs_to :author
end

Autore:

class Author < ActiveRecord::Base
  has_many :articles
end

La View in questione che elenca gli articoli con i relativi autori:

<% for article in @articles %>
    <%= article.title %> : <%= article.author.name %>
<% end %>

Senza Query Trace installato, se provassimo a creare una View in cui viene mostrato l’elenco degli articoli, con il rispettivo autore, otterremmo nel log una cosa simile:

Processing ArticlesController#index (for 127.0.0.1 at 2007-11-19 17:32:21) [GET]
  Session ID: f9f7ea95c88ee5ea8dbfceac4a623fed
  Parameters: {"action"=>"index", "controller"=>"articles"}
  SQL (0.000282)   SET SQL_AUTO_IS_NULL=0
  Article Load (0.000308)   SELECT * FROM articles
Rendering articles/index
  Article Columns (0.002330)   SHOW FIELDS FROM articles
  Author Columns (0.002595)   SHOW FIELDS FROM authors
  Author Load (0.000360)   SELECT * FROM authors WHERE (authors.`id` = 1)
Completed in 0.04941 (20 reqs/sec) | Rendering: 0.00630 (12%) | DB: 0.00588 (11%) | 200 OK [http://localhost/articles]

Dopo l’installazione di Query Trace, la stessa pagina genera un log di questo tipo:

Processing ArticlesController#index (for 127.0.0.1 at 2007-11-19 18:10:18) [GET]
  Session ID: f9f7ea95c88ee5ea8dbfceac4a623fed
  Parameters: {"action"=>"index", "controller"=>"articles"}
  SQL (0.000250)   SET SQL_AUTO_IS_NULL=0
    /Users/abernesco/NetBeansProjects/testopt/app/controllers/articles_controller.rb:3:in `index'
  Article Load (0.000356)   SELECT * FROM articles
    /Users/abernesco/NetBeansProjects/testopt/app/controllers/articles_controller.rb:3:in `index'
Rendering articles/index
  Article Columns (0.002574)   SHOW FIELDS FROM articles
  Author Columns (0.001772)   SHOW FIELDS FROM authors
  Author Load (0.000832)   SELECT * FROM authors WHERE (authors.`id` = 1)
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:2:in `_run_rhtml_47app47views47articles47index46rhtml'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `each'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `_run_rhtml_47app47views47articles47index46rhtml'
Completed in 0.05732 (17 reqs/sec) | Rendering: 0.01116 (19%) | DB: 0.00578 (10%) | 200 OK [http://localhost/articles]

La differenza principale consiste nel fatto che ora, dopo che è iniziato il rendering della pagina, viene indicato il punto esatto della vista dove avviene la chiamata alla query. In questo caso si vede che viene generata la query per recuperare il nome dell’utente autore dell’articolo.

Il primo passo è stato fatto, ora possiamo vedere dove, nelle nostre View avvengono le chiamate al database.

Quando si lavora con ActiveRecords dipendenti è importante verificare se si possono includere nella chiamata ad un oggetto anche le proprietà degli oggetti collegati che ci servono.

Mi spiego meglio. Nel caso dell’articolo, se avessimo potuto richiamare in un unica operazione anche il nome dell’autore, avremmo potuto evitare 1 query. Moltiplicare questa pratica il maggior numero di volte possibile porta ad un risparmio di risorse notevoli.

Nel caso in cui gli articoli fossero 5, il log mostrerebbe questo tipo di situazione:

Rendering articles/index
  Article Columns (0.002059)   SHOW FIELDS FROM articles
  Author Columns (0.002539)   SHOW FIELDS FROM authors
  Author Load (0.001043)   SELECT * FROM authors WHERE (authors.`id` = 1)
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:2:in `_run_rhtml_47app47views47articles47index46rhtml'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `each'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `_run_rhtml_47app47views47articles47index46rhtml'
  Author Load (0.000403)   SELECT * FROM authors WHERE (authors.`id` = 1)
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:2:in `_run_rhtml_47app47views47articles47index46rhtml'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `each'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `_run_rhtml_47app47views47articles47index46rhtml'
  Author Load (0.000278)   SELECT * FROM authors WHERE (authors.`id` = 1)
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:2:in `_run_rhtml_47app47views47articles47index46rhtml'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `each'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `_run_rhtml_47app47views47articles47index46rhtml'
  Author Load (0.000319)   SELECT * FROM authors WHERE (authors.`id` = 1)
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:2:in `_run_rhtml_47app47views47articles47index46rhtml'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `each'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `_run_rhtml_47app47views47articles47index46rhtml'
  Author Load (0.000943)   SELECT * FROM authors WHERE (authors.`id` = 1)
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:2:in `_run_rhtml_47app47views47articles47index46rhtml'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `each'
    /Users/abernesco/NetBeansProjects/testopt/app/views/articles/index.rhtml:1:in `_run_rhtml_47app47views47articles47index46rhtml'
Completed in 0.04515 (22 reqs/sec) | Rendering: 0.02003 (44%) | DB: 0.01528 (33%) | 200 OK [http://localhost/articles]

Ovvero, ogni volta che viene renderizzato un articolo, Rails genera una query verso il database per recuperare il nome dell’autore. Questo tipo di comportamento viene chiamato “1+n query problem”, cioè, alla prima query, quella che recupera gli articoli, si aggiungono poi “n” query per associarvi il nome dell’autore.

La tecnica per risolvere queste situazioni si chiama “eager loading” e consiste nell’inglobare in un’unica chiamata il recupero degli articoli e dell’autore collegato.

Per fare ciò, basta aggiungere l’opzione “:include” al Find dell’oggetto in questione, specificando l’altro oggetto da includere.

class ArticlesController < ApplicationController
  def index
    @articles = Article.find(:all,:include => :author)
  end
end

Rilanciando ora la visualizzazione della pagina, il log file cambia drasticamente:

Processing ArticlesController#index (for 127.0.0.1 at 2007-11-19 18:47:08) [GET]
  Session ID: f9f7ea95c88ee5ea8dbfceac4a623fed
  Parameters: {"action"=>"index", "controller"=>"articles"}
  Article Columns (0.004440)   SHOW FIELDS FROM articles
  Author Columns (0.002770)   SHOW FIELDS FROM authors
  Article Load Including Associations (0.000603)   SELECT articles.`id` AS t0_r0, articles.`title` AS t0_r1, articles.`created_at` AS t0_r2, articles.`content` AS t0_r3, articles.`author_id` AS t0_r4, authors.`id` AS t1_r0, authors.`name` AS t1_r1 FROM articles LEFT OUTER JOIN authors ON authors.id = articles.author_id
    /Users/abernesco/NetBeansProjects/testopt/app/controllers/articles_controller.rb:4:in `index'
  Article Load (0.000321)   SELECT * FROM articles LIMIT 1
    /Users/abernesco/NetBeansProjects/testopt/app/controllers/articles_controller.rb:5:in `index'
Rendering articles/index
Completed in 0.02871 (34 reqs/sec) | Rendering: 0.00283 (9%) | DB: 0.00813 (28%) | 200 OK [http://localhost/articles]

Ovvero, non compaiono più altre query accessorie, in quanto ora l’autore è incluso nella prima chiamata e quindi non è più necessario interrogare il database per ogni articolo. La query ora però è diventata un po’ più complessa, includendo un JOIN e ricaricando assieme tutti i campi dell’articolo e tutti i campi dell’autore.

In generale è possibile ottimizzare ulteriormente la query, a costo di scendere un po’ più in basso e di utilizzare le opzioni “:joins” e “:select” al posto di “:include” per limitare il numero di informazioni che vengono recuperate.

Nel caso precedente infatti, verrebbero caricati in memoria tutti i dati dell’utente, il che potrebbe portare dei problemi di prestazioni nel caso in cui la tabella “authors” contenesse un elevato numero di colonne o colonne con blob di dati molto grossi.

Nel nostro caso, servendoci solo il nome dell’autore, potrebbe essere conveniente andare a specificarlo, tralasciando così il caricamento degli altri campi:

class ArticlesController < ApplicationController
  def index
    #@articles = Article.find(:all)
    @articles = Article.find(:all,
      :joins => "JOIN authors ON articles.author_id = authors.id",
      :select => "articles.title,authors.name AS author_name"
    )
    #@article = Article.find(:first)
  end
end

E’ importante notare che ora il nome dell’autore è diventato un nuovo attributo chiamato “author_name” e che va utilizzato quest’ultimo come riferimento nella vista. Sostituendo nella pagina “article.author.name” con “article.author_name” e ricaricando la pagina possiamo vedere l’ultimo risultato della nostra cura nei log:

Processing ArticlesController#index (for 127.0.0.1 at 2007-11-19 18:54:57) [GET]
  Session ID: f9f7ea95c88ee5ea8dbfceac4a623fed
  Parameters: {"action"=>"index", "controller"=>"articles"}
  Article Load (0.000393)   SELECT articles.title,authors.name AS author_name FROM articles JOIN authors ON articles.author_id = authors.id
    /Users/abernesco/NetBeansProjects/testopt/app/controllers/articles_controller.rb:4:in `index'
Rendering articles/index
  Article Columns (0.003628)   SHOW FIELDS FROM articles
Completed in 0.01183 (84 reqs/sec) | Rendering: 0.00215 (18%) | DB: 0.00590 (49%) | 200 OK [http://localhost/articles]

Concludendo, sapere dove le risorse vengono utilizzate e che tipo di operazioni avvengono realmente sotto il cofano di Rails permette di risparmiare un sacco di brutte sorprese. Anche se non sono indicativi in senso assoluto, i tempi riportati negli stralci dei log pubblicati in questa pagina ne sono un esempio.

Altre informazioni: http://www.infoq.com/articles/Rails-Performance

« Impostare le variabili di applicazione con Ruby On Rails Utilizzare la libreria Swiss Ephemeris con Ruby »


Actions

Informations

Leave a comment

You must be logged in to post a comment