Does anyone understand this huge difference in processing time, when using an intermediate file, or when using a pipe? I'm converting tiff to pdf using standard tools on a fresh debian squeeze server. A standard way of doing this is to convert to ps first.
Without pipe:
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
With pipe:
root@web5:~# time tiff2ps test.tif | ps2pdf13 -sPAPERSIZE=a4 - > test.pdf
real 1m6.098s
user 0m15.861s
sys 0m50.9
During the last command, gs process is at 100% all the time.
Update:
Here is an strace output for the ps generation:
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
Here is an strace output for the piped version: PS generation seems to be much slower when output is piped into 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...
