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)

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 :)

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

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.

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

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

* ,tempo impiegato: in media sec

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: ((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)) -> 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: ((content_type_id = 68) AND (state_id = workflows_state.id)) Total runtime: 47.382 ms (8 righe) (END)