Команда оболочки медленная при использовании канала, быстрая с промежуточным файлом

19

Кто-нибудь понимает эту огромную разницу во времени обработки при использовании промежуточного файла или при использовании канала? Я конвертирую TIFF в PDF, используя стандартные инструменты на свежем сервере Debian Squeeze. Стандартный способ сделать это - сначала преобразовать в ps.

Без трубы:

root@web5:~# time tiff2ps test.tif > test.ps

real    0m0.860s
user    0m0.744s
sys 0m0.112s

root@web5:~# time ps2pdf13 -sPAPERSIZE=a4 test.ps > test.pdf

real    0m0.667s
user    0m0.612s
sys 0m0.060s

С трубой:

root@web5:~# time tiff2ps test.tif | ps2pdf13 -sPAPERSIZE=a4 - > test.pdf

real    1m6.098s
user    0m15.861s
sys 0m50.9

Во время последней команды процесс gs постоянно находится на уровне 100%.

Обновление :
Вот вывод strace для поколения ps:

root@web5:~# strace tiff2ps test.tif > test.ps
execve("/usr/bin/tiff2ps", ["tiff2ps", "test.tif"], [/* 28 vars */]) = 0
brk(0)                                  = 0x1395000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb5a1937000
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=21735, ...}) = 0
mmap(NULL, 21735, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb5a1931000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/libtiff.so.4", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\200\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=405128, ...}) = 0
mmap(NULL, 2501416, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb5a14b9000
mprotect(0x7fb5a151a000, 2093056, PROT_NONE) = 0
mmap(0x7fb5a1719000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x60000) = 0x7fb5a1719000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/libjpeg.so.62", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\3408\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=145048, ...}) = 0
mmap(NULL, 2240080, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb5a1296000
mprotect(0x7fb5a12b9000, 2093056, PROT_NONE) = 0
mmap(0x7fb5a14b8000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7fb5a14b8000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/libz.so.1", O_RDONLY)    = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\"\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=93936, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb5a1930000
mmap(NULL, 2188976, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb5a107f000
mprotect(0x7fb5a1096000, 2093056, PROT_NONE) = 0
mmap(0x7fb5a1295000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0x7fb5a1295000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/libm.so.6", O_RDONLY)        = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360>\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=530736, ...}) = 0
mmap(NULL, 2625768, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb5a0dfd000
mprotect(0x7fb5a0e7d000, 2097152, PROT_NONE) = 0
mmap(0x7fb5a107d000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x80000) = 0x7fb5a107d000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/libc.so.6", O_RDONLY)        = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\355\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1437064, ...}) = 0
mmap(NULL, 3545160, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb5a0a9b000
mprotect(0x7fb5a0bf4000, 2093056, PROT_NONE) = 0
mmap(0x7fb5a0df3000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x158000) = 0x7fb5a0df3000
mmap(0x7fb5a0df8000, 18504, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fb5a0df8000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb5a192f000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb5a192e000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb5a192d000
arch_prctl(ARCH_SET_FS, 0x7fb5a192e700) = 0
mprotect(0x7fb5a0df3000, 16384, PROT_READ) = 0
mprotect(0x7fb5a107d000, 4096, PROT_READ) = 0
mprotect(0x7fb5a1939000, 4096, PROT_READ) = 0
munmap(0x7fb5a1931000, 21735)           = 0
open("test.tif", O_RDONLY)              = 3
brk(0)                                  = 0x1395000
brk(0x13b6000)                          = 0x13b6000
read(3, "II*\0\10\0\0\0", 8)            = 8
fstat(3, {st_mode=S_IFREG|0644, st_size=1825656, ...}) = 0
mmap(NULL, 1825656, PROT_READ, MAP_SHARED, 3, 0) = 0x7fb5a176f000
open("/proc/meminfo", O_RDONLY)         = 4
fstat(4, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb5a1936000
read(4, "MemTotal:        2090844 kB\nMemF"..., 1024) = 1024
close(4)                                = 0
munmap(0x7fb5a1936000, 4096)            = 0
write(2, "TIFFReadDirectory: ", 19TIFFReadDirectory: )     = 19
write(2, "Warning, ", 9Warning, )                = 9
write(2, "test.tif: wrong data type 7 for "..., 59test.tif: wrong data type 7 for "RichTIFFIPTC"; tag ignored) = 59
write(2, ".\n", 2.
)                      = 2
gettimeofday({1334836895, 374666}, NULL) = 0
fstat(1, {st_mode=S_IFREG|0664, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb5a1936000
open("/etc/localtime", O_RDONLY)        = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=1892, ...}) = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=1892, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb5a1935000
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0"..., 4096) = 1892
lseek(4, -1217, SEEK_CUR)               = 675
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\6\0\0\0\6\0\0\0\0"..., 4096) = 1217
close(4)                                = 0
munmap(0x7fb5a1935000, 4096)            = 0
write(1, "%!PS-Adobe-3.0 EPSF-3.0\n%%Creato"..., 4096) = 4096
write(1, "fffffffffffffffffffffffffffff\nff"..., 4096) = 4096
write(1, "ffffffffffffffffffff\nfffffffffff"..., 4096) = 4096
write(1, "fffffffffff\nffffffffffffffffffff"..., 4096) = 4096
write(1, "ff\nfffffffffffffffffffffffffffff"..., 4096) = 4096
write(1, "ffffffffffffffffffffffffffffffff"..., 4096) = 4096
write(1, "ffffffffffffffffffffffffffffffff"..., 4096) = 4096
write(1, "ffffffffffffffffffffffffffffffff"..., 4096) = 4096
write(1, "ffffffffffffffffffffffffffffffff"..., 4096) = 4096
write(1, "ffffffffffffffffffffffff\nfffffff"..., 4096) = 4096

Вот прямой вывод для конвейерной версии: генерация PS кажется намного медленнее, когда вывод передается в ps2pdf13. 

root@web5:~# strace tiff2ps test.tif | ps2pdf13 -sPAPERSIZE=a4 - > test.pdf
execve("/usr/bin/tiff2ps", ["tiff2ps", "test.tif"], [/* 28 vars */]) = 0
brk(0)                                  = 0x1b97000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9208bb1000
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=21735, ...}) = 0
mmap(NULL, 21735, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f9208bab000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/libtiff.so.4", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\200\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=405128, ...}) = 0
mmap(NULL, 2501416, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f9208733000
mprotect(0x7f9208794000, 2093056, PROT_NONE) = 0
mmap(0x7f9208993000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x60000) = 0x7f9208993000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/libjpeg.so.62", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\3408\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=145048, ...}) = 0
mmap(NULL, 2240080, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f9208510000
mprotect(0x7f9208533000, 2093056, PROT_NONE) = 0
mmap(0x7f9208732000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7f9208732000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/libz.so.1", O_RDONLY)    = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\"\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=93936, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9208baa000
mmap(NULL, 2188976, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f92082f9000
mprotect(0x7f9208310000, 2093056, PROT_NONE) = 0
mmap(0x7f920850f000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0x7f920850f000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/libm.so.6", O_RDONLY)        = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360>\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=530736, ...}) = 0
mmap(NULL, 2625768, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f9208077000
mprotect(0x7f92080f7000, 2097152, PROT_NONE) = 0
mmap(0x7f92082f7000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x80000) = 0x7f92082f7000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/libc.so.6", O_RDONLY)        = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\355\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1437064, ...}) = 0
mmap(NULL, 3545160, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f9207d15000
mprotect(0x7f9207e6e000, 2093056, PROT_NONE) = 0
mmap(0x7f920806d000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x158000) = 0x7f920806d000
mmap(0x7f9208072000, 18504, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f9208072000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9208ba9000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9208ba8000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9208ba7000
arch_prctl(ARCH_SET_FS, 0x7f9208ba8700) = 0
mprotect(0x7f920806d000, 16384, PROT_READ) = 0
mprotect(0x7f92082f7000, 4096, PROT_READ) = 0
mprotect(0x7f9208bb3000, 4096, PROT_READ) = 0
munmap(0x7f9208bab000, 21735)           = 0
open("test.tif", O_RDONLY)              = 3
brk(0)                                  = 0x1b97000
brk(0x1bb8000)                          = 0x1bb8000
read(3, "II*\0\10\0\0\0", 8)            = 8
fstat(3, {st_mode=S_IFREG|0644, st_size=1825656, ...}) = 0
mmap(NULL, 1825656, PROT_READ, MAP_SHARED, 3, 0) = 0x7f92089e9000
open("/proc/meminfo", O_RDONLY)         = 4
fstat(4, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9208bb0000
read(4, "MemTotal:        2090844 kB\nMemF"..., 1024) = 1024
close(4)                                = 0
munmap(0x7f9208bb0000, 4096)            = 0
write(2, "TIFFReadDirectory: ", 19TIFFReadDirectory: )     = 19
write(2, "Warning, ", 9Warning, )                = 9
write(2, "test.tif: wrong data type 7 for "..., 59test.tif: wrong data type 7 for "RichTIFFIPTC"; tag ignored) = 59
write(2, ".\n", 2.
)                      = 2
gettimeofday({1334836513, 114140}, NULL) = 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) = 0x7f9208bb0000
open("/etc/localtime", O_RDONLY)        = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=1892, ...}) = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=1892, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f9208baf000
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0"..., 4096) = 1892
lseek(4, -1217, SEEK_CUR)               = 675
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\6\0\0\0\6\0\0\0\0"..., 4096) = 1217
close(4)                                = 0
munmap(0x7f9208baf000, 4096)            = 0
write(1, "%!PS-Adobe-3.0 EPSF-3.0\n%%Creato"..., 4096) = 4096
write(1, "fffffffffffffffffffffffffffff\nff"..., 4096) = 4096
write(1, "ffffffffffffffffffff\nfffffffffff"..., 4096) = 4096
write(1, "fffffffffff\nffffffffffffffffffff"..., 4096) = 4096
write(1, "ff\nfffffffffffffffffffffffffffff"..., 4096) = 4096
write(1, "ffffffffffffffffffffffffffffffff"..., 4096) = 4096
write(1, "ffffffffffffffffffffffffffffffff"..., 4096) = 4096
write(1, "ffffffffffffffffffffffffffffffff"..., 4096) = 4096
write(1, "ffffffffffffffffffffffffffffffff"..., 4096) = 4096
...etc...
linux bash scripting shell-scripting pipe plang
источник
Это большие файлы?
Халед
Нет, совсем нет: 1,8 МБ для файла TIFF.
План
2
@plang: Вы пытались в straceпроцессе GS? Может быть, он обрабатывает файл большими кусками при использовании промежуточного файла, или происходит нечто подобное ...
Янне Пиккарайнен,
Можете ли вы предоставить конкретную версию Ghostscript? gs -v
ewwhite
1
Вот пример: sendpace.com/file/vqoxbs
plang

Ответы:

17

Изменить: я запустил это с вашим исходным файлом в моей среде и получить следующие результаты:

[root@xt ~]# time tiff2ps test.tif > test.ps
real    0m0.795s
user    0m0.659s
sys     0m0.135s

[root@xt ~]# time ps2pdf13 -sPAPERSIZE=a4 test.ps > test.pdf
real    0m0.592s
user    0m0.513s
sys     0m0.075s

[root@xt ~]# time tiff2ps test.tif | ps2pdf13 -sPAPERSIZE=a4 - > test2.pdf
real    0m13.110s
user    0m4.601s
sys     0m7.260s

Я добавил pvкоманду, чтобы увидеть, что происходит. Вот что случилось:

[root@xt ~]# time tiff2ps test.tif | pv | ps2pdf13 -sPAPERSIZE=a4 - > test2.pdf
50.5MB 0:00:12 [4.05MB/s] [                      <=>                                                               ]

real    0m13.934s
user    0m4.751s
sys     0m8.261s

50 мегабайт выходных данных Postscript передаются в ps2pdf13команду! @janneb был прав в том, что это проблема буферизации / канала. Я пытался использовать unbufferкоманду , но Ghostscript не нравится псевдотерминал.

Есть ли причина, по которой вы не можете использовать tiff2pdfкоманду?

[root@xt ~]# time tiff2pdf -o test2.pdf test.tif

real    0m0.242s
user    0m0.176s
sys     0m0.064s
ewwhite
источник
Я вижу разницу, но менее важную, чем с моим тестовым файлом 1,8 МБ.
Plang
1
Привет, я думаю, что вы нашли проблему. Благодарность! Я не знал, что tiff2pdf существует. Работает, очень быстро, но есть проблема: объем вывода составляет 26 МБ, по сравнению с 356 КБ с tiff2ps / ps2pdf13.
Plang
1
Запустите его с помощью сжатия JPEG (384 КБ): tiff2pdf -j -o test.pdf test.tifили сжатия ZIP (1,6 tiff2pdf -z -o test3.pdf test.tif
МБ
1
tiff2pdf с опциями "-j" исправляет проблему с размером.
Plang