venerdì 9 maggio 2014

Hai capyto?

Provo a convincere gli amici che in python usare str.format salva certamente la vita (a patto di sapere come usarla, naturalmente), ma questo non significa che sia meglio usarla sempre e comunque.
Lo snippet lo dimostra in maniera molto banale.

import logging
import time

log = logging.getLogger(__name__)

class SleepingBeauty(object):
    def __init__(self):
        super(SleepingBeauty, self).__init__()
    
    def __str__(self):
        time.sleep(2)
        return "Yaaawn"
       
def test():
    log.info('Starting')
    sb = SleepingBeauty()
    t0 = time.time()
    log.debug('Testing str.format method: {0}'.format(sb))
    t1 = time.time()
    log.debug('Testing old awful method: %s', sb)
    t2 = time.time()
    log.info('Stopped')
    log.info('Now some stats: t1-t0 = %.2f   -   t2-t1 = %.2f', t1-t0, t2-t1)

if __name__ == '__main__':
    logging.basicConfig(level=logging.INFO)
    test()

Il succo della questione è semplice:
Il livello di logging è INFO, quindi le chiamate "log.debug" non produrranno effetti.
Eppure nella prima delle due si pagano due secondi solo per preparare la stringa da passare alla chiamata, salvo poi scoprire che non verrà mai mostrata nei log.
La seconda invece non causa ritardi. Infatti l'esecuzione di "log.debug" termina (a causa dell'incompatibilità con il livello INFO) ben PRIMA di eseguire "str(sb)".
Chiaro, no? :-)