This is an old revision of the document!

GUIDA DI PROFILAZIONE SU DJANGO

premessa: questa guida prevedede che dei file di profilazione siano stati preventivamente creati e che questi risultati vengano analizzati. Una buona libreria python per la profilazione è hotshot.

Noi abbiamo scelto di profilare partendo dalle viste django, in quanto entry-point per l'utente finale, dato che lo scopo è di migliorare l'esperienza utente. Il workflow riportato è comunque applicabile a qualsiasi profilazione.

* for i in `ls -1 /path/to/txt/files/*.txt` ; do printf “%s (Total Time) Profiling file: %s\n” `head -1 $i | awk '{print $8}'` `basename $i` » profiling_stats.txt; done * sort -rn profiling_stats.txt -o profiling_stats.txt (mette in ordine decrescente i tempi)

WORKFLOW GENERALE

Qui si riporta il workflow da seguire una volta localizzate le parti del software che richidono un analisi.

- Guardare: in questa fase si sceglie la profilazione che interessa (di solito quella che riporta un tempo maggiore) e si identifica la funzione (vista, funzione, ecc.) da cui è stata prodotta.

- Riprodurre: in questa fase si riproduce in locale lo stato dell'installazione, compresi i dati, in modo da verificare la corrispondenza tra il comportamento monitorato dalla profilazione e quello effettivo.

- Misurare: Una volta riprodotto il problema provare un'ottimizzazione alla volta e per ognuna registrare l'eventuale aumento/decremnto delle performance.

CONSIGLI: Per l'ottimizzazione partire dagli indici del database ed eventualmente in seguito controllare l'eleganza del codice :)

NELLO SPECIFICO

Nel caso pratio del profiling di GasistaFelice si è scelto di profilare le viste, rispettivamente nelle installazioni sui server:

* `ordini.desmacerata.it`, in `/var/www/gf_desmc; * `gasistafelice.befair.it`, in

Una volta ottenuti i file di profilazione .prof creati dal software, è possibile produrre dei file file di testo da questi eseguendo:

* for i in `ls /path/to/profs/*.prof` ; python /path/to/gasistafelice/manage.py profiled_code $i 20 > `basename $i .prof`.txt; done

Guardare

Si è scelta la vista `insolutes_orders`, profilata:

* in data 2014/05/15 per un tempo totale di 192.639 sec nel server ordini.desmacerata.it * in data per un tempo totale di sec nel server gasistafelice.befair.it

La vista puo essere relativa a una risorsa, il GAS.

Riprodurre

ordini.desmacerata.it

In locale, è stato scelto di riprodurre la chiamata per il GAS gassosa:

* GAS http://127.0.0.1:8000/gasistafelice/rest/gas/8/insolutes_orders/?render_as=list, tempo impiegato: in media ~22 sec

gasistafelice.befair.it

In locale, è stato scelto di riprodurre la chiamata per il GAS gassosa:

* ,tempo impiegato: in media sec

Misurare

Un modo per controllare l'effettivo utilizo degli indici è lanciare dalla dbshell di django la query di Utilizzo degli indici alla pagina postgresql

I test in questa sezione sono stati eseguiti svuotando la cache di postgres prima di ogni test. In un sistema linux:

* service postgresql stop; * echo 3 > /proc/sys/vm/drop_caches; * service postgresql start;

- Ottimizzazione:si prende in cosiderazione la possibilità di inserire un indice multicolonna (content_type, state__name) alla tabella workflows_stateobjectrelation.

1° prova: senza indice multicolonna:

* EXPLAIN ANALYZE SELECT “workflows_stateobjectrelation”.“id”, “workflows_stateobjectrelation”.“content_type_id”, “workflows_stateobjectrelation”.“content_id”, “workflows_stateobjectrelation”.“state_id” FROM “workflows_stateobjectrelation” INNER JOIN “workflows_state” ON (“workflows_stateobjectrelation”.“state_id” = “workflows_state”.“id”) WHERE (“workflows_state”.“name” = 'Closed' AND “workflows_stateobjectrelation”.“content_type_id” = 68 );

QUERY PLAN

Nested Loop (cost=52.76..238.26 rows=495 width=16) (actual time=31.081..47.576 rows=195 loops=1)

> Seq Scan on workflows_state (cost=0.00..1.27 rows=1 width=4) (actual time=8.104..8.121 rows=2 loops=1)

Filter: ¹⁾

> Bitmap Index Scan on workflows_stateobjectrelation_content_type_id_state_id (cost=0.00..29.87 rows=1362 width=0) (actual time=3.330..3.330 rows=98 loops=2)

Index Cond: ²⁾ Total runtime: 47.382 ms (8 righe)

¹⁾

name)::text = 'Closed'::text)

> Bitmap Heap Scan on workflows_stateobjectrelation (cost=52.76..203.37 rows=2689 width=16) (actual time=11.530..19.676 rows=98 loops=2)

Recheck Cond: (state_id = workflows_state.id)

       Filter: (content_type_id = 68)
       ->  Bitmap Index Scan on workflows_stateobjectrelation_state_id  (cost=0.00..52.42 rows=2689 width=0) (actual time=4.860..4.860 rows=98 loops=2)
             Index Cond: (state_id = workflows_state.id)

Total runtime: 47.675 ms (9 righe) (END) 2° prova: dopo l'inserimento dell'indice multicolonna CREATE INDEX “workflows_stateobjectrelation_content_type_id_state_id” ON “workflows_stateobjectrelation” (“content_type_id”,“state_id”); * EXPLAIN ANALYZE SELECT “workflows_stateobjectrelation”.“id”, “workflows_stateobjectrelation”.“content_type_id”, “workflows_stateobjectrelation”.“content_id”, “workflows_stateobjectrelation”.“state_id” FROM “workflows_stateobjectrelation” INNER JOIN “workflows_state” ON (“workflows_stateobjectrelation”.“state_id” = “workflows_state”.“id”) WHERE (“workflows_state”.“name” = 'Closed' AND “workflows_stateobjectrelation”.“content_type_id” = 68 );

       
                   QUERY PLAN

————————————————————————————————————————————————————————– Nested Loop (cost=30.21..182.54 rows=495 width=16) (actual time=31.059..47.288 rows=195 loops=1)

> Seq Scan on workflows_state (cost=0.00..1.27 rows=1 width=4) (actual time=8.068..8.100 rows=2 loops=1)

Filter: ((name)::text = 'Closed'::text)

> Bitmap Heap Scan on workflows_stateobjectrelation (cost=30.21..164.24 rows=1362 width=16) (actual time=11.548..19.552 rows=98 loops=2)

Recheck Cond: ((content_type_id = 68) AND (state_id = workflows_state.id

²⁾

content_type_id = 68) AND (state_id = workflows_state.id

Il nostro punto della strada

Table of Contents