Estadísticas de tiempo de generación del blog

De cara a optimizar la generación de las páginas del blog con multiprogramación, he querido registrar el tiempo que tarda en ejecutar la generación en el ordenador que se genera, para compararla después con la optimización. Para mi sorpresa, la mayor parte del os 8 segundos que lleva la generación se la lleva el leer y compilar el fichero Lisp que contiene las entradas antiguas (1.3MB), mientras que la generación de todas las páginas no tarda más de 4 segundos:

[dsevilla@neuromancer:~/svn/blog]$ sbcl --script packages.lisp
Doing pre-calculations...
Generating index page...
Evaluation took:
  0.116 seconds of real time
  0.120000 seconds of total run time (0.080000 user, 0.040000 system)
  [ Run times consist of 0.040 seconds GC time, and 0.080 seconds non-GC time. ]
  103.45% CPU
  325,871,901 processor cycles
  63,697,264 bytes consed

Generating post pages...
Evaluation took:
  0.408 seconds of real time
  0.410000 seconds of total run time (0.270000 user, 0.140000 system)
  [ Run times consist of 0.010 seconds GC time, and 0.400 seconds non-GC time. ]
  100.49% CPU
  1,144,029,612 processor cycles
  167,055,120 bytes consed

Generating categories pages...
Evaluation took:
  0.074 seconds of real time
  0.070000 seconds of total run time (0.070000 user, 0.000000 system)
  94.59% CPU
  209,026,050 processor cycles
  39,985,040 bytes consed

Generating archives pages...
Evaluation took:
  0.086 seconds of real time
  0.090000 seconds of total run time (0.090000 user, 0.000000 system)
  104.65% CPU
  240,093,459 processor cycles
  43,278,720 bytes consed

Generating RSS...
Evaluation took:
  0.084 seconds of real time
  0.080000 seconds of total run time (0.080000 user, 0.000000 system)
  [ Run times consist of 0.020 seconds GC time, and 0.060 seconds non-GC time. ]
  95.24% CPU
  236,784,003 processor cycles
  35,828,208 bytes consed

Esto hace que la optimización, como máximo, sólo pueda reducir esos 0,4 segundos que tarda la generación. Aún así lo intentaré como un ejercicio de programación. La otra idea será ver optimizar el proceso de carga quizá a través de pre-compilación de los ficheros .lisp. Por cierto, para que luego digan que los lenguajes interpretados son lentos... 1 segundo en generar 34MB de ficheros de texto.

La última sorpresa... Por casualidad he probado clisp... Bien, aquí la carga de los ficheros .lisp es instantánea, y la ejecución es incluso más rápida (diría incluso increíblemente rápida:

[dsevilla@neuromancer:~/svn/blog]$ clisp packages.lisp
Doing pre-calculations...
Generating index page...
Real time: 0.186066 sec.
Run time: 0.19 sec.
Space: 24960736 Bytes
GC: 13, GC time: 0.03 sec.
Generating post pages...
Real time: 0.708989 sec.
Run time: 0.69 sec.
Space: 83706152 Bytes
GC: 36, GC time: 0.06 sec.
Generating categories pages...
Real time: 0.051339 sec.
Run time: 0.05 sec.
Space: 11157832 Bytes
GC: 5, GC time: 0.0 sec.
Generating archives pages...
Real time: 0.249124 sec.
Run time: 0.25 sec.
Space: 13408648 Bytes
GC: 6, GC time: 0.02 sec.
Generating RSS...
Real time: 0.891364 sec.
Run time: 0.88 sec.
Space: 20991880 Bytes
GC: 9, GC time: 0.05 sec.

Comparando el tiempo de ejecución visto por el usuario:

[dsevilla@neuromancer:~/svn/blog]$ time clisp packages.lisp
real	0m2.320s
user	0m1.970s
sys	0m0.310s
[dsevilla@neuromancer:~/svn/blog]$ time sbcl --script packages.lisp
real	0m10.405s
user	0m9.940s
sys	0m0.440s

Esto es, ¡5 veces más rápido en general clisp que sbcl! Sin embargo, mirando los datos de cada parte, hay resultados muy extraños e inconsistentes. Por ejemplo, clisp tarda casi un segundo en generar RSS, mientras que sbcl tarda 0,08 segundos (un orden de magnitud menos). Estudiaré el código para ver dónde puede estar el problema, pero por ahora, usaré clisp para generar el blog, aunque use sbcl, con el magnífico entorno Slime para Emacs para seguir programando y probando.

blog comments powered by Disqus