imap cmd="/usr/bin/strace -q -v -s200 -f -F -o /home/cyrus/pop3 /full/path/to/imapd -C /etc/imapd.domain4.com.conf " listen="192.168.110.175:imap" maxchild=-1 maxforkrate=100
Also just noticed that in your cyrus.conf file the SERVICES names are not unique. They all are named imap, imaps, sieve, or lmtp. Not sure about 2.4.18 but in the 3.0.1 man page it says "In the SERVICES section, names must be unique." Wouldn't hurt naming them different to see if that makes a difference.
On 05/23/2017 11:38 AM, Michael Ulitskiy wrote:
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@lists.andrew.cmu.edu From Michael Ulitskiy <mulits...@acedsl.com> Reply-To: Michael Ulitskiy <mulits...@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@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: cy...@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---- 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
<<attachment: boutilpj.vcf>>
---- 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