Multi-thread cyrus delayed forking of imapd processes after connecting to master listener

Michael Hieb michael.hieb at celoso.net
Tue May 23 06:19:17 EDT 2017


The SASL is cyrus-sasl 2.1.26-9.5. I believe it does use /dev/urandom.

I am not sure how to run strace on the process that the Master listener 
forks. Here is the strace run on the imapd process at a command prompt 
(which is not quite the same as the master listener forking it to a port 
where another process is waiting to connect to it).

MAILSERVER:~ # strace /usr/lib/cyrus/bin/imapd -C 
/etc/imapd.domain1.com.conf
execve("/usr/lib/cyrus/bin/imapd", ["/usr/lib/cyrus/bin/imapd", "-C", 
"/etc/imapd.domain1.com.conf"], [/* 56 vars */]) = 0
brk(0)                                  = 0x5573deaf5000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb770c000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or 
directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=80522, ...}) = 0
mmap(NULL, 80522, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fdeb76f8000
close(3)                                = 0
open("/usr/lib64/libsasl2.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\300N\0\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=118552, ...}) = 0
mmap(NULL, 2213800, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb72d0000
mprotect(0x7fdeb72ec000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb74eb000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1b000) = 0x7fdeb74eb000
close(3)                                = 0
open("/usr/lib64/libkrb5.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200Y\2\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=855280, ...}) = 0
mmap(NULL, 2951008, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb6fff000
mprotect(0x7fdeb70c1000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb72c0000, 65536, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xc1000) = 0x7fdeb72c0000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb76f7000
open("/lib64/libcom_err.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340\26\0\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=14760, ...}) = 0
mmap(NULL, 2109928, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb6dfb000
mprotect(0x7fdeb6dfe000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb6ffd000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fdeb6ffd000
close(3)                                = 0
open("/lib64/libssl.so.1.0.0", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0pr\1\0\0\0\0\0"..., 832) 
= 832
fstat(3, {st_mode=S_IFREG|0555, st_size=440632, ...}) = 0
mmap(NULL, 2535888, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb6b8f000
mprotect(0x7fdeb6bf0000, 2097152, PROT_NONE) = 0
mmap(0x7fdeb6df0000, 45056, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x61000) = 0x7fdeb6df0000
close(3)                                = 0
open("/lib64/libcrypto.so.1.0.0", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\313\6\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0555, st_size=2447744, ...}) = 0
mmap(NULL, 4559184, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb6735000
mprotect(0x7fdeb6962000, 2097152, PROT_NONE) = 0
mmap(0x7fdeb6b62000, 167936, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22d000) = 0x7fdeb6b62000
mmap(0x7fdeb6b8b000, 12624, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fdeb6b8b000
close(3)                                = 0
open("/usr/lib64/libdb-4.8.so", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 at X\2\0\0\0\0\0"..., 832) 
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1560248, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb76f6000
mmap(NULL, 3655304, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb63b8000
mprotect(0x7fdeb6530000, 2097152, PROT_NONE) = 0
mmap(0x7fdeb6730000, 20480, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x178000) = 0x7fdeb6730000
close(3)                                = 0
open("/lib64/libz.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P#\0\0\0\0\0\0"..., 832) 
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=88216, ...}) = 0
mmap(NULL, 2183304, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb61a2000
mprotect(0x7fdeb61b7000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb63b6000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14000) = 0x7fdeb63b6000
close(3)                                = 0
open("/lib64/libwrap.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p8\0\0\0\0\0\0"..., 832) 
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=40952, ...}) = 0
mmap(NULL, 2139520, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb5f97000
mprotect(0x7fdeb5fa0000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb619f000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x8000) = 0x7fdeb619f000
mmap(0x7fdeb61a1000, 1408, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fdeb61a1000
close(3)                                = 0
open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\10\2\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1925280, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb76f5000
mmap(NULL, 3811872, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb5bf4000
mprotect(0x7fdeb5d8e000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb5f8d000, 24576, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x199000) = 0x7fdeb5f8d000
mmap(0x7fdeb5f93000, 14880, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fdeb5f93000
close(3)                                = 0
open("/lib64/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\r\0\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=18712, ...}) = 0
mmap(NULL, 2109680, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb59f0000
mprotect(0x7fdeb59f2000, 2097152, PROT_NONE) = 0
mmap(0x7fdeb5bf2000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fdeb5bf2000
close(3)                                = 0
open("/usr/lib64/libk5crypto.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340K\0\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=191424, ...}) = 0
mmap(NULL, 2290168, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb57c0000
mprotect(0x7fdeb57ed000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb59ec000, 12288, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2c000) = 0x7fdeb59ec000
mmap(0x7fdeb59ef000, 504, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fdeb59ef000
close(3)                                = 0
open("/usr/lib64/libkrb5support.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20:\0\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=52416, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb76f4000
mmap(NULL, 2147816, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb55b3000
mprotect(0x7fdeb55bf000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb57be000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xb000) = 0x7fdeb57be000
close(3)                                = 0
open("/lib64/libkeyutils.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320\26\0\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=14688, ...}) = 0
mmap(NULL, 2109704, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb53af000
mprotect(0x7fdeb53b2000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb55b1000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fdeb55b1000
close(3)                                = 0
open("/lib64/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\2209\0\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=97152, ...}) = 0
mmap(NULL, 2189896, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb5198000
mprotect(0x7fdeb51ac000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb53ab000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13000) = 0x7fdeb53ab000
mmap(0x7fdeb53ad000, 6728, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fdeb53ad000
close(3)                                = 0
open("/lib64/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360r\0\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=135952, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb76f3000
mmap(NULL, 2213008, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb4f7b000
mprotect(0x7fdeb4f93000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb5192000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x17000) = 0x7fdeb5192000
mmap(0x7fdeb5194000, 13456, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fdeb5194000
close(3)                                = 0
open("/lib64/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0ps\0\0\0\0\0\0"..., 832) 
= 832
fstat(3, {st_mode=S_IFREG|0755, st_size=147208, ...}) = 0
mmap(NULL, 2251056, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb4d55000
mprotect(0x7fdeb4d78000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb4f77000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7fdeb4f77000
mmap(0x7fdeb4f79000, 6448, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fdeb4f79000
close(3)                                = 0
open("/usr/lib64/libpcre.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0000\30\0\0\0\0\0\0"..., 
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=452976, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb76f2000
mmap(NULL, 2548232, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 
0) = 0x7fdeb4ae6000
mprotect(0x7fdeb4b54000, 2093056, PROT_NONE) = 0
mmap(0x7fdeb4d53000, 8192, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6d000) = 0x7fdeb4d53000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb76f1000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb76f0000
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb76ee000
arch_prctl(ARCH_SET_FS, 0x7fdeb76ee840) = 0
mprotect(0x7fdeb5f8d000, 16384, PROT_READ) = 0
mprotect(0x7fdeb5192000, 4096, PROT_READ) = 0
mprotect(0x7fdeb4d53000, 4096, PROT_READ) = 0
mprotect(0x7fdeb5bf2000, 4096, PROT_READ) = 0
mprotect(0x7fdeb4f77000, 4096, PROT_READ) = 0
mprotect(0x7fdeb53ab000, 4096, PROT_READ) = 0
mprotect(0x7fdeb55b1000, 4096, PROT_READ) = 0
mprotect(0x7fdeb57be000, 4096, PROT_READ) = 0
mprotect(0x7fdeb59ec000, 8192, PROT_READ) = 0
mprotect(0x7fdeb619f000, 4096, PROT_READ) = 0
mprotect(0x7fdeb63b6000, 4096, PROT_READ) = 0
mprotect(0x7fdeb6730000, 8192, PROT_READ) = 0
mprotect(0x7fdeb6b62000, 110592, PROT_READ) = 0
mprotect(0x7fdeb6df0000, 16384, PROT_READ) = 0
mprotect(0x7fdeb6ffd000, 4096, PROT_READ) = 0
mprotect(0x7fdeb72c0000, 53248, PROT_READ) = 0
mprotect(0x7fdeb74eb000, 4096, PROT_READ) = 0
mprotect(0x5573dd954000, 8192, PROT_READ) = 0
mprotect(0x7fdeb770d000, 4096, PROT_READ) = 0
munmap(0x7fdeb76f8000, 80522)           = 0
set_tid_address(0x7fdeb76eeb10)         = 18042
set_robust_list(0x7fdeb76eeb20, 24)     = 0
rt_sigaction(SIGRTMIN, {0x7fdeb4f81d80, [], SA_RESTORER|SA_SIGINFO, 
0x7fdeb4f8bb10}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {0x7fdeb4f81e10, [], 
SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fdeb4f8bb10}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
statfs("/sys/fs/selinux", 0x7ffe1b4e8b00) = -1 ENOENT (No such file or 
directory)
statfs("/selinux", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, 
f_blocks=474903111, f_bfree=452714842, f_bavail=452228240, 
f_files=120627200, f_ffree=120300880, f_fsi\
d={352889743, -1913047647}, f_namelen=255, f_frsize=4096}) = 0
brk(0)                                  = 0x5573deaf5000
brk(0x5573deb16000)                     = 0x5573deb16000
open("/proc/filesystems", O_RDONLY)     = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb770b000
read(3, "nodev\tsysfs\nnodev\trootfs\nnodev\tr"..., 1024) = 297
read(3, "", 1024)                       = 0
close(3)                                = 0
munmap(0x7fdeb770b000, 4096)            = 0
access("/etc/selinux/config", F_OK)     = -1 ENOENT (No such file or 
directory)
stat("/dev/urandom", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 3
read(3, "\355\207\254Q\253\17d\266\22x\324\257 
\236\205H\327b\32\221nzmx\251\216D\257J\362\301\357"..., 60) = 60
close(3)                                = 0
open("/dev/urandom", O_RDONLY|O_NOCTTY|O_NONBLOCK|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
poll([{fd=3, events=POLLIN}], 1, 10)    = 1 ([{fd=3, revents=POLLIN}])
read(3, 
"r\324\5\243C\224\n\222d\333\25\25\2738\7\ts\351\3759\265\207&\n\251}\316\205\224v\17\253"..., 
1024) = 1024
close(3)                                = 0
getuid()                                = 0
stat("/dev/urandom", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 3
read(3, "\3323i\236\226J\353\241\201\213\20\30\201b<\371\5\246\234\230", 
20) = 20
close(3)                                = 0
stat("/dev/urandom", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"u2V%3\367\276\251\202$\376_\1\365r`N^\5?\303H\330\3173i\335\247]A\222\376"..., 
256) = 256
close(3)                                = 0
stat("/dev/urandom", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\333_\2\335]:\7\"\373s]\352\375\305\312t\244.@;\245\345\245^(\262d\350\273[\327-"..., 
216) = 216
close(3)                                = 0
stat("/dev/urandom", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 3
read(3, "\207", 1)                      = 1
close(3)                                = 0
stat("/dev/urandom", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 3
read(3, "\332", 1)                      = 1
close(3)                                = 0
stat("/dev/urandom", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"\22\335\242$\210`\376\376d\200\215m\213-\0162\r\257\206\335\nY\343\3376/\224\352\360\312\336\360", 
32) = 32
close(3)                                = 0
stat("/dev/urandom", {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
open("/dev/urandom", O_RDONLY|O_CLOEXEC) = 3
read(3, 
"U\2\251M\21fm\345\334\215Q1(\253\1M!\270\226\212s&A\263}\351\16\271", 
28) = 28
close(3)                                = 0
futex(0x7fdeb5bf30a8, FUTEX_WAKE_PRIVATE, 2147483647) = 0
open("/lib64/.libcrypto.so.1.0.0.hmac", O_RDONLY) = -1 ENOENT (No such 
file or directory)
open("/proc/sys/crypto/fips_enabled", O_RDONLY) = -1 ENOENT (No such 
file or directory)
access("/lib64/.libcrypto.so.1.0.0.hmac", F_OK) = -1 ENOENT (No such 
file or directory)
open("/etc/localtime", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=127, ...}) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=127, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) 
= 0x7fdeb770b000
read(3, 
"TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\1\0\0\0\0"..., 4096) 
= 127
lseek(3, -71, SEEK_CUR)                 = 56
read(3, 
"TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\1\0\0\0\1\0\0\0\0"..., 4096) = 71
close(3)                                = 0
munmap(0x7fdeb770b000, 4096)            = 0
socket(PF_LOCAL, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 3
connect(3, {sa_family=AF_LOCAL, sun_path="/dev/log"}, 110) = 0
sendto(3, "<11>May 23 10:11:18 imapd: could"..., 67, MSG_NOSIGNAL, NULL, 
0) = 67
exit_group(70)                          = ?
+++ exited with 70 +++

Michael


On 05/19/2017 05:55 PM, Michael Ulitskiy wrote:

Msg # 	57050 	Previous in Sequence 
<http://asg.andrew.cmu.edu/archive/message.php?mailbox=archive.info-cyrus&msg=57374> 
	
Date 	Fri, 19 May 2017 11:32:38 -0400
To 	info-cyrus at lists.andrew.cmu.edu
>From 	Michael Ulitskiy <mulitskiy at acedsl.com>
Reply-To: 	Michael Ulitskiy <mulitskiy at acedsl.com>
Subject 	Re: Multi-thread cyrus delayed forking of imapd processes after 
connecting to master listener

My immediate guess is it blocks at reading /dev/random.
strace should show you exactly where it blocks.
What version of SASL are you using? Newer versions have switched to /dev/urandom AFAIK

Michael

On Friday, May 19, 2017 05:48:36 PM Michael Hieb wrote:
> Apologies for long post, most of it is configuration details.
> 
> I have recently changed from a single threaded cyrus server in which 
> multiple domains were overloaded on one listener as multiple virtual 
> domains to a multiple threaded cyrus server in which multiple domains 
> are listened for on separate ip addresses with separate configurations. 
> The primary motivation was to have separate tls certificates for each 
> domain. The problem is that I can connect to cyrus listener on all 
> ip/ports for all domains, but while one of them will fork immediately 
> and respond with a banner, the others will delay for a period of time 
> from a few seconds to a minute or so before forking and responding with 
> a banner. With the same setup, I change to a single threaded cyrus 
> server to listen on all ip/ports then I get an immediate response on 
> all, but of course I do not get the separate tls certificate or 
> configuration. It is replicable that switching between the single 
> threaded and multiple threaded configuration triggers the problem. I 
> have searched the logs and the mail-lists and found nothing that seems 
> related.
> 
> Question: why does switching to multiple threaded cyrus server trigger 
> delayed forking of imapd processes after connecting to master listener?
> 
> On listener which responds immediately (as expected) I get this:
> 
> user at somehost:~> telnet imap.domain1.com 143
> Trying 192.168.110.171...
> Connected to imap.domain1.com.
> Escape character is '^]'.
> * OK [CAPABILITY IMAP4rev1 LITERAL+ ID ENABLE STARTTLS AUTH=GSS-SPNEGO 
> AUTH=GSSAPI AUTH=DIGEST-MD5 AUTH=CRAM-MD5 AUTH=LOGIN AUTH=PLAIN SASL-IR] 
> imap.domain1.com Cyrus IMAP v2.4.18 server ready
> 
> On listener with delay, I get this (and process hangs for many seconds 
> or even a minute or two):
> 
> user at somehost:~> telnet imap.domain2.com 143
> Trying 192.168.110.171...
> Connected to imap.domain2.com.
> Escape character is '^]'.
> 
> The domain for which the listener responds and the one for which it 
> delays seems to change and be random as far as I can tell.
> 
> There is nothing in the log journal that looks different from when we 
> connect and get a for and when we connect and get a delay.
> 
> May 19 09:44:31 MAILSERVER master[13762]: about to exec 
> /usr/lib/cyrus/bin/imapd
> May 19 09:44:31 MAILSERVER imap[13762]: executed
> May 19 09:44:31 MAILSERVER imap[13762]: IOERROR: opening 
> /var/lib/imap/user_deny.db: No such file or directory
> 
> and once imapd forks and banner is generated
> 
> May 19 09:46:45 MAILSERVER imap[13814]: accepted connection
> 
> Here are the configuration details:
> 
> I run cyrus 2.4.18-3.6 on openSuSE Leap 42.2 Linux MAILSERVER 
> 4.4.62-18.6-default #1 SMP Fri Apr 21 16:14:48 UTC 2017 (84f9824) x86_64 
> x86_64 x86_64 GNU/Linux.
> 
> Here is my (sanitized) cyrus.conf and one imapd.conf (they all look 
> alike except for certificate and domain specifics).
> 
> MAILSERVER:~ # cat /etc/cyrus.conf
> START {
> # do not delete this entry!
> recover cmd="ctl_cyrusdb -r"
> 
> # this is only necessary if using idled for IMAP IDLE
> idled cmd="idled"
> }
> 
> # UNIX sockets start with a slash and are put into /var/lib/imap/socket
> SERVICES {
> # add or remove based on preferences
> #imap cmd="imapd" listen="imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain1.com.conf " 
> listen="192.168.171.4:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain1.com.conf " 
> listen="192.168.110.171:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain2.com.conf " 
> listen="192.168.172.4:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain2.com.conf " 
> listen="192.168.110.172:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain3.com.conf " 
> listen="192.168.174.4:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain3.com.conf " 
> listen="192.168.110.174:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain4.com.conf " 
> listen="192.168.175.4:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain4.com.conf " 
> listen="192.168.110.175:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain5.com.conf " 
> listen="192.168.176.4:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain5.com.conf " 
> listen="192.168.110.176:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain6.com.conf " 
> listen="192.168.177.4:imap" maxchild=-1 maxforkrate=100
> imap cmd="imapd -C /etc/imapd.domain6.com.conf " 
> listen="192.168.110.177:imap" maxchild=-1 maxforkrate=100
> 
> #imaps cmd="imapd -s" listen="imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain1.com.conf -s " 
> listen="192.168.171.4:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain1.com.conf -s " 
> listen="192.168.110.171:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain2.com.conf -s " 
> listen="192.168.172.4:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain2.com.conf -s " 
> listen="192.168.110.172:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain3.com.conf -s " 
> listen="192.168.174.4:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain3.com.conf -s " 
> listen="192.168.110.174:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain4.com.conf -s " 
> listen="192.168.175.4:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain4.com.conf -s " 
> listen="192.168.110.175:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain5.com.conf -s " 
> listen="192.168.176.4:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain5.com.conf -s " 
> listen="192.168.110.176:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain6.com.conf -s " 
> listen="192.168.177.4:imaps" maxchild=-1 maxforkrate=100
> imaps cmd="imapd -C /etc/imapd.domain6.com.conf -s " 
> listen="192.168.110.177:imaps" maxchild=-1 maxforkrate=100
> 
> #pop3 cmd="pop3d" listen="pop3"
> #pop3s cmd="pop3d -s" listen="pop3s"
> #sieve cmd="timsieved" listen="sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain1.com.conf" 
> listen="192.168.171.4:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain1.com.conf" 
> listen="192.168.110.171:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain2.com.conf" 
> listen="192.168.172.4:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain2.com.conf" 
> listen="192.168.110.172:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain3.com.conf" 
> listen="192.168.174.4:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain3.com.conf" 
> listen="192.168.110.174:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain4.com.conf" 
> listen="192.168.175.4:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain4.com.conf" 
> listen="192.168.110.175:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain5.com.conf" 
> listen="192.168.176.4:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain5.com.conf" 
> listen="192.168.110.176:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain6.com.conf" 
> listen="192.168.177.4:sieve" maxchild=-1 maxforkrate=100
> sieve cmd="timsieved -C /etc/imapd.domain6.com.conf" 
> listen="192.168.110.177:sieve" maxchild=-1 maxforkrate=100
> 
> #ptloader cmd="ptloader" listen="/var/lib/imap/ptclient/ptsock"
> 
> # at least one LMTP is required for delivery
> lmtp cmd="lmtpd -a" listen="mail.domain1.com:lmtp" maxchild=-1 
> maxforkrate=100
> lmtp cmd="lmtpd -a" listen="mail.domain2.com:lmtp" maxchild=-1 
> maxforkrate=100
> lmtp cmd="lmtpd -a" listen="mail.domain3.com:lmtp" maxchild=-1 
> maxforkrate=100
> lmtp cmd="lmtpd -a" listen="mail.domain4.com:lmtp" maxchild=-1 
> maxforkrate=100
> lmtp cmd="lmtpd -a" listen="mail.domain5.com:lmtp" maxchild=-1 
> maxforkrate=100
> lmtp cmd="lmtpd -a" listen="mail.domain6.com:lmtp" maxchild=-1 
> maxforkrate=100
> #lmtpunix cmd="lmtpd" listen="/var/lib/imap/socket/lmtp"
> 
> # this is only necessary if using notifications
> #notify cmd="notifyd" listen="/var/lib/imap/socket/notify" proto="udp"
> }
> 
> EVENTS {
> # this is required
> checkpoint cmd="ctl_cyrusdb -c" period=30
> 
> # this is only necessary if using duplicate delivery suppression,
> # Sieve or NNTP
> duplicateprune cmd="cyr_expire -E 3" at=0400
> 
> # Expire data older then 69 days. Two full months of 31 days
> # each includes two full backup cycles, plus 1 week margin
> # because we run our full backups on the first sat/sun night
> # of each month.
> deleteprune cmd="cyr_expire -E 4 -D 69" at=0430
> expungeprune cmd="cyr_expire -E 4 -X 69" at=0445
> 
> # this is only necessary if caching TLS sessions
> tlsprune cmd="tls_prune" at=0400
> 
> # Uncomment the next entry, if you want to automatically remove
> # old messages of EVERY user.
> # This example calls ipurge every 60 minutes and ipurge will delete
> # ALL messages older then 120 days.
> # enter 'man 8 ipurge' for more details
> #cleanup cmd="ipurge -d 120 -f" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain1.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain2.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain3.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain4.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain5.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Spam*@domain6.com" period=60
> 
> cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain1.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain2.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain3.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain4.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain5.com" period=60
> cleanup cmd="ipurge -f -d 30 user/%/Trash*@domain6.com" period=60
> 
> cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain1.com" period=60
> cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain2.com" period=60
> cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain3.com" period=60
> cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain4.com" period=60
> cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain5.com" period=60
> cleanup cmd="ipurge -f -d 60 user/%/Sent*@domain6.com" period=60
> 
> # Create search indexes regularly
> squatter cmd="squatter -s -i" at=0530
> 
> # running sa-learn
> sa-learn cmd="/usr/local/bin/cyrus-salearn.pl" period=60
> sa-update cmd="/usr/bin/sa-update -v" at=0000
> 
> }
> 
> MAILSERVER:~ # cat /etc/imapd.domain1.com.conf
> configdirectory: /var/lib/imap
> partition-default: /var/spool/imap
> sievedir: /var/lib/sieve
> annotation_definitions: /etc/imapd.annotations.conf
> # admins: cyrus at domain1.net
> allowanonymouslogin: no
> autocreatequota: 10000
> reject8bit: no
> quotawarn: 90
> timeout: 30
> poptimeout: 10
> dracinterval: 0
> drachost: localhost
> sasl_pwcheck_method: saslauthd
> lmtp_overquota_perm_failure: no
> #lmtp_catchall_mailbox: admin
> lmtp_downcase_rcpt: yes
> lmtp_fuzzy_mailbox_match: yes
> expunge_mode: delayed
> deletedprefix: DELETED
> delete_mode: delayed
> 
> # added by Michael Hieb Jun 22 2014
> allowplaintext: yes
> unixhierarchysep: yes
> allowplainwithouttls: no
> altnamespace: no
> virtdomains: userid
> servername: imap.domain1.net
> 
> #
> # if you want TLS, you have to generate certificates and keys
> #
> tls_cert_file: /etc/letsencrypt/live/imap.domain1.net/cert.pem
> tls_key_file: /etc/letsencrypt/live/imap.domain1.net/privkey.pem
> tls_ca_file: /etc/letsencrypt/live/imap.domain1.net/chain.pem
> tls_ca_path: /etc/ssl/certs
> tls_versions: tls1_0 tls1_1 tls1_2
> 
> # added by Michael Hieb 20-Jan-2017 for lmtp on port (not socket)
> lmtp_admins: lmtpuser
> MAILSERVER:~ #
> 
> Note: before I discovered the problem with forking could be triggered by 
> switching between single threaded and multi-threaded cyrus server, I 
> thought problem could be related to resource constraints. This is why I 
> set all processes with maxchild=-1 maxforkrate=100. I also set the 
> following in /etc/systemd/system/cyrus.service
> 
> MAILSERVER:~ # cat /etc/systemd/system/cyrus.service
> [deleted...]
> LimitRTPRIO=50000
> LimitNOFILE=50000
> LimitNPROC=50000
> MAILSERVER:~ #
> 
> None of these resource settings made any difference and the problem goes 
> away as soon as cyrus is single threaded - so I do not believe it is a 
> resource constraint (at least one I understand at this point).
> 
> Any help would be much appreciated.
> 
> 
> 
> ----
> Cyrus Home Page: http://www.cyrusimap.org/
> List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
> To Unsubscribe:
> https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus

	


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.andrew.cmu.edu/pipermail/info-cyrus/attachments/20170523/6a2b4659/attachment-0001.html>


More information about the Info-cyrus mailing list