Creando 30.000 tablas con PostgreSQL
Esta mañana leyendo los mensajes de Twitter que me llegaron por la noche, me encontre con uno que me llamó la atención, “Steward Smith blogs on Optimazing InnoDB for creating 30.000 tables (and nothing else)".
Empece a leerlo y estuvo entretenido. Trataba de lo que se podia hacer para acelerar la creación de muchos objetos en MySQL usando InnoDB, esto es especialmente importante cuando se vaya a importar una nueva base de datos que sea grande.
Una de las cosas que decia, con la que estoy de acuerdo, es que en estos casos la durabilidad de los datos no es importante hasta que terminemos con la creación de todos los objetos, por lo que podemos apagar todos los mecanismos implementados en la base de datos para garantizar esta durabilidad mientras que estemos importando.
El test del que hablaba este artículo consistía en crear 30.000 tablas, insertar una fila en cada tabla y destruir las 30.000 tablas. Como me pico la curiosidad, me puse manos a la obra para ver como PostgreSQL funcionaba ejecutando un test similar.
Primero ejecuté el test con todos los parametros que garantizan la durabilidad de los datos activados.
Estos son los valores de los parametros relevantes para este test en una máquina con 8GB de memoria y postgreSQL 9.1.1 (especialmente importante es max_locks_per_transaction si no quereis que el test falle estrepitosamente):
max_connections = 100
shared_buffers = 2GB
work_mem = 16MB
maintenance_work_mem = 256MB
max_stack_depth = 4MB
wal_level = archive
fsync = on
synchronous_commit = on
wal_sync_method = fdatasync
checkpoint_segments = 128
max_locks_per_transaction = 1000
Y esto lo ejecutado para realizar el test:
CREATE DATABASE pgtest2;
\c pgtest2
\timing
DO
$$
BEGIN
FOR i IN 1..30000 LOOP
EXECUTE 'CREATE TABLE table' || i || '(id INT, PRIMARY KEY (id))';
END LOOP;
END$$;
DO
$$
BEGIN
FOR i IN 1..30000 LOOP
EXECUTE 'INSERT INTO table' || i || ' VALUES (' || i || ')';
END LOOP;
END$$;
DO
$$
BEGIN
FOR i IN 1..30000 LOOP
EXECUTE 'DROP TABLE table' || i;
END LOOP;
END$$;
La creación de todas las tablas duró 49818.792 ms, la inserción de una fila en cada una de ellas 37681.864 ms y la destrucción de las 30.000 tablas 548185.154 ms. Bueno, la creación e inserción de datos en 87.5 segundos no esta nada mal, me dejo un poco sorprendido que la destrucción de todas las tablas durase 9.1 minutos. En total 10.5 minutos, no estaba nada mal para tener todo lo referente a durabilidad activado.
Si lo comparamos con los números conseguidos con MySQL usando InnoDB con las opciones por defecto de “MySQL test suite”, está pero que muy bien, ya que en el mejor de los casos estaban consiguiendo unas 20-25 tablas por segundo, con lo cual hubieran tardado unos 20 minutos en terminar.
Era hora de empezar a apagar parámetros relacionados con la durabilidad de los datos. El primero synchronous_commit, lo apagamos y volvemos a ejecutar el test.
Para este test en concreto, el apagado de este parámetro no afecta prácticamente en nada al resultado final, (47834.357 ms, 37889.342 ms y 546201.158 ms respectivamente). La explicación que yo le encuentro a esto es que todo lo ejecutado en un bloque DO se ejecuta dentro de una misma transacción, con lo que en realidad estamos ejecutando solamente 3 transacciones.
Seguimos, definimos wal_level = minimal, fsync = off y vamos a ver si conseguimos una mejora en la velocidad.
Con este cambio si que obtenemos una importante mejora en la creación y la inserción (31823.101 ms y 35474.310 ms respectivamente), en total 67.2 segundos, que supone una reducción de 20.3 segundos o lo que es lo mismo un 23.2% menos de tiempo con respecto a la primera vez. La destrucción de las tablas no mejora en absoluto (547486.861 ms)
En una situación real en la que estemos importando una base de datos grande no vamos a destruir seguidamente los datos importados, asi que el uso de wal_level = minimal, fsync = off y synchronous_commit = off nos puede ahorrar en general una gran cantidad de tiempo. No olvidar volver a cambiar estos parámetros al terminar para asegurar la durabilidad de los datos.
Me quedo con la duda de porque la destrucción de todas las tablas dura tanto, especialmente cuando la creación de las mismas ha tardado solamente 31 segundos. Haciendo un strace al proceso que está ejecutando las ordenes, podemos ver que una serie de operaciones de este tipo se repiten durante todo el tiempo que el proceso se está ejecutando:
open("base/42616854/42941855", O_RDWR) = 10
close(10) = 0
open("base/42616854/42941855", O_RDWR) = 10
ftruncate(10, 0) = 0
close(10) = 0
unlink("base/42616854/42941855.1") = -1 ENOENT (No such file or directory)
open("base/42616854/42941855_fsm", O_RDWR) = -1 ENOENT (No such file or directory)
open("base/42616854/42941855_vm", O_RDWR) = -1 ENOENT (No such file or directory)
open("base/42616854/42941855_init", O_RDWR) = -1 ENOENT (No such file or directory)
Parece ser que está intentando limpiar y encontrar una serie de ficheros asociados a cada tabla que está destruyendo y esto es lo que consume todo el tiempo, especialmente cuando estos ficheros todavía no se encuentran en el sistema. ¿Quizás alguien tenga alguna información de porque esto es así y si se puede hacer algo para mejorar los tiempos de destrucción de tablas?
Los tiempos totales conseguidos con strace -c -p son:
CREACION de tablas:
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
61.12 0.087196 0 184077 64014 open
18.07 0.025772 1 44762 write
12.43 0.017730 633 28 munmap
3.20 0.004565 0 120074 close
2.41 0.003438 0 164859 lseek
1.97 0.002811 0 60003 1 stat
0.46 0.000655 0 3340 sendto
0.29 0.000419 0 4652 brk
0.03 0.000042 0 139 read
0.01 0.000019 0 820 semop
0.01 0.000012 0 430 kill
0.00 0.000000 0 1 fstat
0.00 0.000000 0 59 mmap
0.00 0.000000 0 1 mprotect
0.00 0.000000 0 1 rt_sigreturn
0.00 0.000000 0 1 select
0.00 0.000000 0 2 setitimer
0.00 0.000000 0 4 recvfrom
0.00 0.000000 0 1 unlink
0.00 0.000000 0 1 futex
------ ----------- ----------- --------- --------- ----------------
100.00 0.142659 583255 64015 total
INSERCION de filas:
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
40.93 0.047498 1 60000 write
39.83 0.046216 0 120004 60000 open
12.85 0.014908 0 30002 read
3.06 0.003555 0 119021 lseek
2.38 0.002763 0 60005 close
0.95 0.001103 0 6671 sendto
0.00 0.000000 0 22 brk
0.00 0.000000 0 1 rt_sigreturn
0.00 0.000000 0 2 setitimer
0.00 0.000000 0 4 recvfrom
0.00 0.000000 0 13 kill
0.00 0.000000 0 20 semop
------ ----------- ----------- --------- --------- ----------------
100.00 0.116043 395765 60000 total
DESTRUCCION de tablas:
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
69.45 0.330171 6 60000 ftruncate
17.79 0.084591 0 300009 180000 open
8.29 0.039411 1 60000 60000 unlink
2.81 0.013347 404 33 brk
1.65 0.007838 0 120008 close
0.00 0.000011 0 369 kill
0.00 0.000010 0 707 semop
0.00 0.000000 0 8 read
0.00 0.000000 0 1 write
0.00 0.000000 0 6 lseek
0.00 0.000000 0 1 rt_sigreturn
0.00 0.000000 0 2 setitimer
0.00 0.000000 0 6 sendto
0.00 0.000000 0 4 recvfrom
------ ----------- ----------- --------- --------- ----------------
100.00 0.475379 541154 240000 total
Casi un 70% del tiempo es consumido por ftruncate
Queda decir que en este pequeño test realizado con MySQL usando InnoDB, consiguieron reducir los tiempos de ejecución a 180 segundos. PostgreSQL consigue ejecutar las dos partes relevantes del test en 67 segundos, pero tarda mucho en la destrucción de los datos.
También hay que decir que esta comparación entre los tiempos conseguidos con MySQL y PostgreSQL es totalmente inútil al haberse realizado en máquinas diferentes, y al no saber la definición de la tabla que utilizaron, con lo que no podemos comparar los resultados. De todas maneras ahí quedan los datos para el que le interese estas cosas.