Por que o printf do bash é mais rápido que / usr / bin / printf?

Question

Eu tenho duas maneiras de chamar printf no meu 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

Então, um é um bash embutido e o outro é um executável compilado apropriado. Eu teria esperado um programa cujo único trabalho seja printf seja muito mais rápido que o shell embutido. Concedido, o builtin já está carregado na memória, mas o tempo de execução real deve ser mais rápido em um programa dedicado, certo? Seria otimizado para fazer uma coisa muito bem no melhor da filosofia Unix.

Aparentemente não:

$ >/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

Grande parte disso, como aponta o @Guru, é o custo de criar encadeamentos que só é incorrido por /usr/bin/printf . Se isso fosse tudo, eu esperaria que o executável fosse mais rápido que o construído se fosse executado fora de um loop. Infelizmente, /usr/bin/printf tem um limite para o tamanho de uma variável que pode ser usada, portanto, só posso testar isso com uma string relativamente curta:

$ 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

O builtin ainda é consistentemente e significativamente mais rápido. Para torná-lo ainda mais claro, vamos iniciar os novos processos:

$ 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

A única razão que posso pensar é que a variável sendo impressa é interna para bash e pode ser passada diretamente para o builtin. Isso é suficiente para explicar a diferença de velocidade? Que outros fatores estão em jogo?

    

Answer 1

Printf autônomo

Parte da "despesa" ao invocar um processo é que várias coisas precisam acontecer e são intensivas em recursos.

1. O executável precisa ser carregado a partir do disco, o que resulta em lentidão, pois o HDD pode ser acessado para carregar o blob binário do disco em que o executável está armazenado.
2. O executável é normalmente construído usando bibliotecas dinâmicas, portanto, alguns arquivos secundários para o executável também terão que ser carregados (ou seja, mais dados de blob binários serão lidos do HDD).
3. Sobrecarga do sistema operacional. Cada processo que você invoca gera sobrecarga na forma de um ID de processo que precisa ser criado para ele. O espaço na memória também será esculpido para acomodar os dados binários que estão sendo carregados do HDD nos passos 1 e amp; 2, assim como várias estruturas que precisam ser preenchidas para armazenar coisas como o ambiente dos processos (variáveis de ambiente, etc.)

trecho de um strace 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, "7ELF
    $ 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, "7ELF%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%>%pre%%pre%%pre%%pre%p7!74%pre%%pre%%pre%"..., 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)                           = ?*
%pre%%pre%%pre%%pre%%pre%%pre%%pre%%pre%>%pre%%pre%%pre%%pre%p7!74%pre%%pre%%pre%"..., 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)                           = ?*

Olhando o acima, você pode ter uma noção dos recursos adicionais que o /usr/bin/printf está tendo que incorrer devido a ser um executável autônomo.

printf embutido

Com a versão compilada de printf , todas as bibliotecas das quais ela depende, bem como seu blob binário, já foram carregadas na memória quando o Bash foi invocado. Então, nada disso precisa ser incorrido novamente.

Efetivamente, quando você chama os "comandos" internos para o Bash, você está realmente fazendo o que equivale a uma chamada de função, já que tudo já foi carregado.

Uma analogia

Se você já trabalhou com uma linguagem de programação, como o Perl, é equivalente a fazer chamadas para a função ( system("mycmd") ) ou usar os backticks ( 'mycmd' ). Quando você faz uma dessas coisas, você está criando um processo separado com sua própria sobrecarga, em vez de usar as funções que lhe são oferecidas através das funções centrais do Perl.

Anatomia do gerenciamento de processos do Linux

Há um artigo muito bom sobre o IBM Developerworks que divide os vários aspectos de como os processos do Linux são criados e destruídos junto com as diferentes bibliotecas C envolvidas no processo. O artigo é intitulado: Anatomia do gerenciamento de processos do Linux - Criação, gerenciamento, programação e destruição . Também está disponível como PDF .

    

Answer 2

Execução de um comando externo /usr/bin/printf leva a uma criação de processo que um shell embutido não possui. Então, para um loop de 3000, 3000 processos criados e, portanto, mais lentos.

Você pode verificar isso executando-os fora de um loop:

    

Answer 3

Embora o tempo de desova e configuração de um novo processo e carregamento, execução e inicialização, limpeza e encerramento de um programa e suas dependências de biblioteca ofusquem de longe, o tempo realmente necessário para executar a ação já foi coberto, aqui estão alguns horários com diferentes implementações printf para uma ação cara que não é ofuscada pelo restante:

$ 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

Você pode ver que, pelo menos a esse respeito, o GNU printf não foi otimizado para desempenho. Não faz muito sentido otimizar um comando como printf , pois, para 99,999% dos usos, o tempo gasto na execução da ação será ofuscado pelo tempo de execução. Faz muito mais sentido otimizar comandos como grep ou sed que podem potencialmente processar gigabytes de dados em uma execução.