¿Por qué el printf de bash es más rápido que /usr/bin/printf?

Question

Tengo dos formas de llamar printfa mi sistema:

$ type -a printf
printf is a shell builtin
printf is /usr/bin/printf
$ file /usr/bin/printf
/usr/bin/printf: ELF 64-bit LSB  executable, x86-64, version 1 (SYSV), dynamically
linked (uses shared libs), for GNU/Linux 2.6.32,
BuildID[sha1]=d663d220e5c2a2fc57462668d84d2f72d0563c33, stripped

Entonces, uno es un bash incorporado y el otro es un ejecutable compilado adecuado. Habría esperado un programa cuyo único trabajo fuera printfmucho más rápido que el shell integrado. Por supuesto, la función incorporada ya está cargada en la memoria, pero el tiempo de ejecución real debería ser más rápido en un programa dedicado, ¿verdad? Estaría optimizado para hacer algo muy bien con lo mejor de la filosofía Unix.

Aparentemente no:

$ >/tmp/foo; time for i in `seq 1 3000`; do printf '%s ' "$i" >> /tmp/foo; done;
real    0m0.065s
user    0m0.036s
sys     0m0.024s

$ >/tmp/foo; time for i in `seq 1 3000`; do /usr/bin/printf '%s ' "$i" >> /tmp/foo; done;   
real    0m18.097s
user    0m1.048s
sys     0m7.124s

Mucho de esto, como señala @Guru, se debe al costo de crear subprocesos en el que solo incurre /usr/bin/printf. Si eso fuera todo, esperaría que el ejecutable fuera más rápido que el integrado si se ejecuta fuera de un bucle. Desafortunadamente, /usr/bin/printftiene un límite en el tamaño de una variable que puede tomar, por lo que solo pude probar esto con una cadena relativamente corta:

$ i=$(seq 1 28000 | awk '{k=k$1}END{print k}'); time /usr/bin/printf '%s ' "$i" > /dev/null; 

real    0m0.035s
user    0m0.004s
sys     0m0.028s

$ i=$(seq 1 28000 | awk '{k=k$1}END{print k}'); time printf '%s ' "$i" > /dev/null; 

real    0m0.008s
user    0m0.008s
sys     0m0.000s

La versión integrada sigue siendo constante y significativamente más rápida. Para hacerlo aún más claro, hagamos que ambos inicien nuevos procesos:

$ time for i in `seq 1 1000`; do /usr/bin/printf '%s ' "$i" >/dev/null; done;   
real    0m33.695s
user    0m0.636s
sys     0m30.628s

$ time for i in `seq 1 1000`; do bash -c "printf '%s ' $i" >/dev/null; done;   

real    0m3.557s
user    0m0.380s
sys     0m0.508s

La única razón que se me ocurre es que la variable que se está imprimiendo es interna bashy se puede pasar directamente a la función incorporada. ¿Es eso suficiente para explicar la diferencia de velocidad? ¿Qué otros factores están en juego?

Answer 1

Impresión independiente

Parte del "gasto" de invocar un proceso es que tienen que suceder varias cosas que requieren muchos recursos.

1. El ejecutable debe cargarse desde el disco, esto genera lentitud ya que se debe acceder al disco duro para cargar el blob binario desde el disco en el que está almacenado el ejecutable.
2. El ejecutable normalmente se crea utilizando bibliotecas dinámicas, por lo que también será necesario cargar algunos archivos secundarios del ejecutable (es decir, se leen más datos de blobs binarios desde el disco duro).
3. Sobrecarga del sistema operativo. Cada proceso que invoca genera una sobrecarga en forma de un ID de proceso que debe crearse para él. También se habrá creado espacio en la memoria para albergar los datos binarios que se cargan desde el disco duro en los pasos 1 y 2, así como para llenar múltiples estructuras para almacenar cosas como el entorno de los procesos (variables de entorno, etc.)

extracto de un fragmento de/usr/bin/printf

    $ strace /usr/bin/printf "%s\n" "hello world"
    *execve("/usr/bin/printf", ["/usr/bin/printf", "%s\\n", "hello world"], [/* 91 vars */]) = 0
    brk(0)                                  = 0xe91000
    mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd155a6b000
    access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
    open("/etc/ld.so.cache", O_RDONLY)      = 3
    fstat(3, {st_mode=S_IFREG|0644, st_size=242452, ...}) = 0
    mmap(NULL, 242452, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fd155a2f000
    close(3)                                = 0
    open("/lib64/libc.so.6", O_RDONLY)      = 3
    read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\357!\3474\0\0\0"..., 832) = 832
    fstat(3, {st_mode=S_IFREG|0755, st_size=1956608, ...}) = 0
    mmap(0x34e7200000, 3781816, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x34e7200000
    mprotect(0x34e7391000, 2097152, PROT_NONE) = 0
    mmap(0x34e7591000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x191000) = 0x34e7591000
    mmap(0x34e7596000, 21688, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x34e7596000
    close(3)                                = 0
    mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd155a2e000
    mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd155a2c000
    arch_prctl(ARCH_SET_FS, 0x7fd155a2c720) = 0
    mprotect(0x34e7591000, 16384, PROT_READ) = 0
    mprotect(0x34e701e000, 4096, PROT_READ) = 0
    munmap(0x7fd155a2f000, 242452)          = 0
    brk(0)                                  = 0xe91000
    brk(0xeb2000)                           = 0xeb2000
    brk(0)                                  = 0xeb2000
    open("/usr/lib/locale/locale-archive", O_RDONLY) = 3
    fstat(3, {st_mode=S_IFREG|0644, st_size=99158752, ...}) = 0
    mmap(NULL, 99158752, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fd14fb9b000
    close(3)                                = 0
    fstat(1, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
    mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fd155a6a000
    write(1, "hello world\n", 12hello world
    )           = 12
    close(1)                                = 0
    munmap(0x7fd155a6a000, 4096)            = 0
    close(2)                                = 0
    exit_group(0)                           = ?*

Al observar lo anterior, puede tener una idea de los recursos adicionales en los que /usr/bin/printfse debe incurrir debido a que es un ejecutable independiente.

Impresión incorporada

Con la versión integrada, printftodas las bibliotecas de las que depende, así como su blob binario, ya se cargaron en la memoria cuando se invocó Bash. Así que no hay que volver a incurrir en nada de eso.

Efectivamente, cuando llamas a los "comandos" integrados de Bash, en realidad estás haciendo lo que equivale a una llamada de función, ya que todo ya ha sido cargado.

Una analogía

Si alguna vez has trabajado con un lenguaje de programación, como Perl, es equivalente a realizar llamadas a la función ( system("mycmd")) o usar las comillas invertidas ( `mycmd`). Cuando haces cualquiera de esas cosas, estás bifurcando un proceso separado con su propia sobrecarga, en lugar de usar las funciones que se te ofrecen a través de las funciones principales de Perl.

Anatomía de la gestión de procesos de Linux

Hay un artículo bastante bueno sobre IBM Developerworks que desglosa los diversos aspectos de cómo se crean y destruyen los procesos de Linux junto con las diferentes bibliotecas C involucradas en el proceso. El artículo se titula:Anatomía de la gestión de procesos de Linux: creación, gestión, programación y destrucción. También está disponible comoPDF.

Answer 2

La ejecución de un comando externo /usr/bin/printfconduce a la creación de un proceso que un shell integrado no hace. Entonces, para un ciclo de 3000, se crean 3000 procesos y, por lo tanto, son más lentos.

Puedes comprobar esto ejecutándolos fuera de un bucle:

Answer 3

Si bien ya se ha cubierto el hecho de que el tiempo de generación y configuración de un nuevo proceso y de carga, ejecución e inicialización, limpieza y finalización de un programa y sus dependencias de biblioteca eclipsa por mucho el tiempo realmente necesario para realizar la acción, aquí Hay algunos tiempos con diferentes printfimplementaciones para una acción costosa que esnoeclipsado por el resto:

$ time /usr/bin/printf %2000000000s > /dev/null
/usr/bin/printf %2000000000s > /dev/null  13.72s user 1.42s system 99% cpu 15.238 total

$ time busybox printf %2000000000s > /dev/null
busybox printf %2000000000s > /dev/null  1.50s user 0.49s system 95% cpu 2.078 total


$ time bash -c 'printf %2000000000s' > /dev/null
bash -c 'printf %2000000000s' > /dev/null  4.59s user 3.35s system 84% cpu 9.375 total

$ time zsh -c 'printf %2000000000s' > /dev/null
zsh -c 'printf %2000000000s' > /dev/null  1.48s user 0.24s system 81% cpu 2.115 total

$ time ksh -c 'printf %2000000000s' > /dev/null
ksh -c 'printf %2000000000s' > /dev/null  0.48s user 0.00s system 88% cpu 0.543 total

$ time mksh -c 'printf %2000000000s' > /dev/null
mksh -c 'printf %2000000000s' > /dev/null  13.59s user 1.57s system 99% cpu 15.262 total

$ time ash -c 'printf %2000000000s' > /dev/null
ash -c 'printf %2000000000s' > /dev/null  13.74s user 1.42s system 99% cpu 15.214 total

$ time yash -c 'printf %2000000000s' > /dev/null
yash -c 'printf %2000000000s' > /dev/null  13.73s user 1.40s system 99% cpu 15.186 total

Puedes ver que al menos en ese sentido, GNU printfno ha sido optimizado para el rendimiento. De todos modos , no tiene mucho sentido optimizar un comando printfporque, para el 99,999% de los usos, el tiempo dedicado a realizar la acción se verá eclipsado por el tiempo de ejecución de todos modos. Tiene mucho más sentido optimizar comandos como grepo sedque potencialmente pueden procesar gigabytes de datos enunocorrer.