you can use 'strace -p <pid>', specifying the pid of process you want to
trace. you will have to "catch" the process that blocks. it may not be easy,
but I have no other suggestions.
On Tuesday, May 23, 2017 06:19:17 PM Michael Hieb wrote:
> 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@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\20
> 5\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/\22
> 4\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&ms
> g=57374>
>
> Date Fri, 19 May 2017 11:32:38 -0400
> To info-cyrus@xxxxxxxxxxxxxxxxxxxx
> From Michael Ulitskiy <mulitskiy@xxxxxxxxxx>
> Reply-To: Michael Ulitskiy <mulitskiy@xxxxxxxxxx>
> 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@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@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@xxxxxxxxxxx
> > 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
----
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
