C Pulando linha no terminal, esclarecimento apenas [RESOLVIDO]

paulo1205
(usa Ubuntu)

Enviado em 13/11/2021 - 11:42h

Nos meus programas, quando quero apenas pular linha, sempre uso putchar('\n') (ou fputc('\n', arquivo), não não for no terminal). Mas eu raramente uso isso. Sempre que possível, tento combinar as escritas das quebras de linha com alguma operação de escrita mais complexa que venha imediatamente antes ou imediatamente depois.

Só de ler a documentação de printf(), puts() e putchar(), já dá para inferir que uma função que tem de fazer parsing de uma string de formatação antes de escrever tal string, como printf(), tem tudo para ser mais lenta do uma que escreve a string sem fazer parsing nenhum, como puts()†, e que essa última, que escreve uma string mais um caráter, tem tudo para ser mais lenta do que outra que escreve apenas um caráter, como putchar().

Porém, existe a questão da escala e dos overheads: para escrever algumas centenas de caracteres mais uma quebra de linha, possivelmente será mais eficiente chamar fputs() apenas uma vez com uma string que agregue essas centenas de caracteres do que chamar putchar() centenas de vezes seguidas‡, a fim de escrever individualmente cada um desses caracteres, pois cada chamada e cada retorno de função tem um custo para a execução do programa.

Dentro do padrão do C, não existe operação de escrita mais simples do que a que se realiza com putchar().


Agora, sobre alguns pontos que surgiram ao longo da discussão.


Medir a eficiência de operações individuais tem grande chance de não ser muito relevante, especialmente se a operação for escrever uma marca de fim de linha, pois cada marca de fim de linha enviada ao terminal provoca o imediato envio dessa mudança de linha para o terminal, já que o buffer de saída ligado ao terminal é orientado a linha por padrão, e o que se estará medindo, na prática, será o tempo gasto pelo sistema para invocar a chamada write(), que descarrega, de uma vez, todo o conteúdo do buffer no terminal, que é uma operação que tende a ser bem mais lenta do que o parsing realizado por printf(), ainda mais com uma string de formatação curta.

Outra questão é quanto ao fato de a primeira operação de escrita ser mais lenta que as demais. Quando li, logo imaginei que era porque a primeira operação de escrita, fosse ela com qualquer uma das funções sugeridas pelo ApprenticeX, teria de providenciar a alocação inicial do buffer de saída, coisa que a segunda operação e as demais já não teriam de fazer novamente.

Para confirmar, imaginei o seguinte programinha, para, depois de compilado, ser rodado sob o strace.

#include <stdio.h>
#include <sys/stat.h>

int main(void){
    struct stat st;
    lstat(".", &st);    // Marcador somente, para eu saber onde acabam as
                        // chamadas referentes à inicialização do programa,
                        // depois das quais começam as providências associ-
                        // adas ao código dentro de main().
    putchar('\n');
    for(int i=0; i<5; ++i){
        lstat(".", &st);
        putchar('\n');
    }
    lstat(".", &st);
} 

$ gcc -static -Wall -Werror -O2 -pedantic-errors x.c -o x
$ strace ./x
execve("./x", ["./x"], 0x7fff130e3f70 /* 63 vars */) = 0
brk(NULL)                               = 0x195e000
brk(0x195f1c0)                          = 0x195f1c0
arch_prctl(ARCH_SET_FS, 0x195e880)      = 0
uname({sysname="Linux", nodename="kvmsrv01.ap.ppires.org", ...}) = 0
readlink("/proc/self/exe", "/tmp/x", 4096) = 6
brk(0x19801c0)                          = 0x19801c0
brk(0x1981000)                          = 0x1981000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
lstat(".", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=33, ...}) = 0
fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(136, 1), ...}) = 0
write(1, "\n", 1
)                       = 1
lstat(".", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=33, ...}) = 0
write(1, "\n", 1
)                       = 1
lstat(".", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=33, ...}) = 0
write(1, "\n", 1
)                       = 1
lstat(".", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=33, ...}) = 0
write(1, "\n", 1
)                       = 1
lstat(".", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=33, ...}) = 0
write(1, "\n", 1
)                       = 1
lstat(".", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=33, ...}) = 0
write(1, "\n", 1
)                       = 1
lstat(".", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=33, ...}) = 0
exit_group(0)                           = ?
+++ exited with 0 +++ 

Note que entre a primeira ocorrência de lstat(".", ...), (na décima linha da saída do strace) e a primeira chamada a write(1, ...) (na décima-segunda linha) existe uma chamada a fstat(1, ...). Esse 1 como argumento de fstat() é o descritor do arquivo associado à saída padrão, que está sendo testado para saber se a saída padrão está associada a um terminal, para então usar buffer orientado a linha, ou se não a um terminal, caso em que será usado um buffer que só é descarregado quando fica completamente cheio. Para as demais ocorrências de lstat() e write(), não existe nenhuma outra operação no meio, confirmando a hipótese de que a inicialização do buffer só acontece uma vez, e que isso se dá quando se executa a primeira operação de escrita do programa usando aquele stream. Essa é razão pela qual a primeira operação é mais lenta.

Voltando à questão da medida de eficiência, mais alguns pontos que eu vi enquanto estava escrevendo a resposta desta mensagem.

O primeiro é que eu vi que o GCC substitui algumas chamadas a funções de saída por outras, principalmente quando a string passada como argumento é simples. Por exemplo, vejam como o programa seguinte, ao gerar código em Assembly, substitui a chamada a printf() por uma chamada a getchar().

#include <stdio.h>

int main(void){
    putchar('\n');
    puts("");
    printf("\n");
} 

$ gcc -O0 -Wall -Werror -pedantic-errors -fverbose-asm -S y.c -c
$ cat y.s
/* Algumas linhas de comentário no topo do arquivo suprimidas. */
        .text
        .section        .rodata
.LC0:
        .string ""
        .text
        .globl  main
        .type   main, @function
main:
.LFB0:
        .cfi_startproc
        pushq   %rbp    #
        .cfi_def_cfa_offset 16
        .cfi_offset 6, -16
        movq    %rsp, %rbp      #,
        .cfi_def_cfa_register 6
# y.c:4:        putchar('\n');
        movl    $10, %edi       #,
        call    putchar@PLT     #
# y.c:5:        puts("");
        leaq    .LC0(%rip), %rdi        #,
        call    puts@PLT        #
# y.c:6:        printf("\n");
        movl    $10, %edi       #,
        call    putchar@PLT     #
        movl    $0, %eax        #, _5
# y.c:7: }
        popq    %rbp    #
        .cfi_def_cfa 7, 8
        ret
        .cfi_endproc
.LFE0:
        .size   main, .-main
        .ident  "GCC: (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0"
        .section        .note.GNU-stack,"",@progbits 

Para evitar a otimização acima, podemos usar a opção -fno-builtin do GCC.

$ gcc -O0 -Wall -Werror -pedantic-errors -fverbose-asm -fno-builtin -S y.c -c
$ cat y.s
/* Algumas linhas de comentário no topo do arquivo suprimidas. */
        .text
        .section        .rodata
.LC0:
        .string ""
.LC1:
        .string "\n"
        .text
        .globl  main
        .type   main, @function
main:
.LFB0:
        .cfi_startproc
        pushq   %rbp    #
        .cfi_def_cfa_offset 16
        .cfi_offset 6, -16
        movq    %rsp, %rbp      #,
        .cfi_def_cfa_register 6
# y.c:4:        putchar('\n');
        movl    $10, %edi       #,
        call    putchar@PLT     #
# y.c:5:        puts("");
        leaq    .LC0(%rip), %rdi        #,
        call    puts@PLT        #
# y.c:6:        printf("\n");
        leaq    .LC1(%rip), %rdi        #,
        movl    $0, %eax        #,
        call    printf@PLT      #
        movl    $0, %eax        #, _5
# y.c:7: }
        popq    %rbp    #
        .cfi_def_cfa 7, 8
        ret
        .cfi_endproc
.LFE0:
        .size   main, .-main
        .ident  "GCC: (Ubuntu 7.5.0-3ubuntu1~18.04) 7.5.0"
        .section        .note.GNU-stack,"",@progbits[/b] 

Além disso, provavelmente é pouco relevante do ponto de vista estatístico medir apenas uma operação. Acredito que seria mais apropriado realizar alguns (ou muitos) milhares de operações consecutivas de um mesmo tipo, e depois dividir o tempo total pela quantidade de operações, se for realmente necessário saber esse tempo individualizado, com algo como o seguinte.

#include <stdio.h>
#include <time.h>

#define OP_MAX 100000000u

int main(void){
    setlinebuf(stdout); // Força buffer orientado a linha, mesmo que não seja um terminal.

    // Só para garantir a inicialização do stream antes do teste propriamente dito.
    putchar('\n');
    fflush(stdout);

    clock_t start, end;

    start=clock();
    for(unsigned i=0; i<OP_MAX; ++i)
        putchar('\n');
    end=clock();
    fprintf(stderr, "Tempo para %u de putchar()s: %fs.\n", OP_MAX, (double)(end-start)/CLOCKS_PER_SEC);

    start=clock();
    for(unsigned i=0; i<OP_MAX; ++i)
        puts("");
    end=clock();
    fprintf(stderr, "Tempo para %u de puts()s: %fs.\n", OP_MAX, (double)(end-start)/CLOCKS_PER_SEC);

    start=clock();
    for(unsigned i=0; i<OP_MAX; ++i)
        printf("\n");
    end=clock();
    fprintf(stderr, "Tempo para %u de printf()s: %fs.\n", OP_MAX, (double)(end-start)/CLOCKS_PER_SEC);

    start=clock();
    for(unsigned i=0; i<OP_MAX; ++i)
        putchar_unlocked('\n');
    end=clock();
    fprintf(stderr, "Tempo para %u de putchar_unlocked()s: %fs.\n", OP_MAX, (double)(end-start)/CLOCKS_PER_SEC);
} 

$ gcc -static -Wall -Werror -O2 -pedantic-errors -O2 x.c -o x
$ ./x > /dev/null
Tempo para 100000000 de putchar()s: 39.047441s.
Tempo para 100000000 de puts()s: 39.829803s.
Tempo para 100000000 de printf()s: 39.246048s.
Tempo para 100000000 de putchar_unlocked()s: 38.999111s.
$ gcc -fno-builtin -static -Wall -Werror -O2 -pedantic-errors -O2 x.c -o x
$ ./x > /dev/null
Tempo para 100000000 de putchar()s: 39.069366s.
Tempo para 100000000 de puts()s: 39.968769s.
Tempo para 100000000 de printf()s: 41.510248s.
Tempo para 100000000 de putchar_unlocked()s: 38.873645s. 

Repare a diferença entre os tempos de execução compilando sem -fno-builtin e com essa opção. Note como, com ela, putchar() é mais eficiente que puts() e mais ainda que printf(), e que putchar_unlocked(), que pode ser feita como macro, já que não se protege contra riscos da execução de múltiplas threads. Mas o maior fator consumidor de tempo em todas essas chamadas é, como eu disse antes, a descarga do buffer a cada quebra de linha. Se tirarmos a chamada a setlinebuf() do programa acima, é de se supor que a execução que não esteja ligada ao terminal será muito mais eficiente (e note que eu alterei o programa também para passar de cem milhões de execuções para um bilhão — dez vezes mais).

$ gcc -static -Wall -Werror -O2 -pedantic-errors -O2 x.c -o x
$ ./x >/dev/null
Tempo para 1000000000 de putchar()s: 1.632126s.
Tempo para 1000000000 de puts()s: 11.005662s.
Tempo para 1000000000 de printf()s: 4.055162s.
Tempo para 1000000000 de putchar_unlocked()s: 1.761776s.
$ gcc -fno-builtin -static -Wall -Werror -O2 -pedantic-errors -O2 x.c -o x
$ ./x >/dev/null
Tempo para 1000000000 de putchar()s: 2.125477s.
Tempo para 1000000000 de puts()s: 9.659515s.
Tempo para 1000000000 de printf()s: 22.045084s.
Tempo para 1000000000 de putchar_unlocked()s: 1.659177s. 

Agora, sim, aparecem de modo mais relevante os overheads de cada uma das funções (ou macros), já que o componente relativo às chamadas ao sistema operacional, que são muito mais custosas, tem seu efeito diminuído. Mas ainda podemos tentar reduzi-lo ainda mais, usando um buffer grande o suficiente para acumular todas as operações antes de ser descarregado.

#include <stdio.h>
#include <time.h>

#define OP_MAX 1000000000u

char buffer[OP_MAX+1];

int main(void){
    setvbuf(stdout, buffer, _IOFBF, sizeof buffer);

    // Só para garantir a inicialização do stream antes do teste propriamente dito.
    putchar('\n');
    fflush(stdout);

    clock_t start, end;

    start=clock();
    for(unsigned i=0; i<OP_MAX; ++i)
        putchar('\n');
    fflush(stdout);
    end=clock();
    fprintf(stderr, "Tempo para %u de putchar()s: %fs.\n", OP_MAX, (double)(end-start)/CLOCKS_PER_SEC);

    start=clock();
    for(unsigned i=0; i<OP_MAX; ++i)
        puts("");
    fflush(stdout);
    end=clock();
    fprintf(stderr, "Tempo para %u de puts()s: %fs.\n", OP_MAX, (double)(end-start)/CLOCKS_PER_SEC);

    start=clock();
    for(unsigned i=0; i<OP_MAX; ++i)
        printf("\n");
    fflush(stdout);
    end=clock();
    fprintf(stderr, "Tempo para %u de printf()s: %fs.\n", OP_MAX, (double)(end-start)/CLOCKS_PER_SEC);

    start=clock();
    for(unsigned i=0; i<OP_MAX; ++i)
        putchar_unlocked('\n');
    fflush(stdout);
    end=clock();
    fprintf(stderr, "Tempo para %u de putchar_unlocked()s: %fs.\n", OP_MAX, (double)(end-start)/CLOCKS_PER_SEC);
} 

$ gcc -static -Wall -Werror -O2 -pedantic-errors -O2 x.c -o x
$ ./x >/dev/null
Tempo para 1000000000 de putchar()s: 1.642850s.
Tempo para 1000000000 de puts()s: 8.987328s.
Tempo para 1000000000 de printf()s: 3.713881s.
Tempo para 1000000000 de putchar_unlocked()s: 1.600242s.
$ gcc -fno-builtin -static -Wall -Werror -O2 -pedantic-errors -O2 x.c -o x
$ ./x >/dev/null
Tempo para 1000000000 de putchar()s: 1.654119s.
Tempo para 1000000000 de puts()s: 9.137192s.
Tempo para 1000000000 de printf()s: 19.001352s.
Tempo para 1000000000 de putchar_unlocked()s: 1.483557s. 

----------
† Dizer que não há parsing em puts()/fputs() pode ser incorreto, dependendo da implementação e do tipo de buffer associado ao stream de saída. Por exemplo, se o stream tiver sido aberto em modo texto e o buffer for orientado a linha, provavelmente haverá parsing para procurar o caráter de fim de linha, que implica a operação de esvaziamento imediato do buffer. Mas cumpre notar que esse parser é muito mais simples do que aquele de printf().

‡ Dependendo da implementação, putchar() pode usar macro, em lugar de chamada de função. Nesse caso, pode ser que não haja overheads de chamada e de retorno, como os que haveria se a chamada fosse uma função. A glibc não usa macro para putchar() por causa de regras de proteção contra execução conflitante em programas com múltiplas threads. A macro que traz o comportamento tradicional de putchar() sem se preocupar com threads se chama putchar_unlocked().


... Então Jesus afirmou de novo: “(...) eu vim para que tenham vida, e a tenham plenamente.” (João 10:7-10)