Hello!
Thanks for your suggestion. It seems to be some Permission denies in
the trace-file that comes below:
------------------------------------------------------
....
....
....
read(15, "\27\3\3\0\340", 5) = 5
read(15,
"R_4\322w\5\231\277S\36\306\374\330\217\320$\306\242\247\264\226\335o\1\355S:\204_\222\312\16"..., 224) =
224
getsockopt(15, SOL_SOCKET, SO_SNDBUF, [2626560], [4]) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
write(15,
"\27\3\3\0\220\260\25\323z7S\354\35oE\227\320\255\227\376\331\234\3472\354\241H\23\351\35\0\223"..., 149) =
149
read(15, 0x7f4e5a2bf343, 5) = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=15, events=POLLIN}], 1, 300000) = 1 ([{fd=15, revents=POLLIN}])
read(15, "\27\3\3\0\240", 5) = 5
read(15,
"\273g/%\236\276\231\237\224+\343Sw\360\353\274\\,\356\370\211\20L\246\270\337Jb\223A\201 "..., 160) =
160
rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
socket(PF_LOCAL, SOCK_STREAM, 0) = 16
fcntl(16, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(16, F_SETFL, O_RDWR) = 0
connect(16, {sa_family=AF_LOCAL, sun_path="private/bounce"}, 110) = 0
poll([{fd=16, events=POLLOUT}], 1, 3600000) = 1 ([{fd=16, revents=POLLOUT}])
write(16, "nrequest\0000\0flags\0000\0queue_id\00067C9"..., 469) = 469
poll([{fd=16, events=POLLIN}], 1, 3600000) = 1 ([{fd=16,
revents=POLLIN|POLLHUP}])
read(16, 0x7f4e5a2cc180, 4096) = -1 EACCES (Permission denied)
close(16) = 0
socket(PF_LOCAL, SOCK_STREAM, 0) = 16
fcntl(16, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(16, F_SETFL, O_RDWR) = 0
connect(16, {sa_family=AF_LOCAL, sun_path="private/defer"}, 110) = 0
poll([{fd=16, events=POLLOUT}], 1, 3600000) = 1 ([{fd=16, revents=POLLOUT}])
write(16, "nrequest\0000\0flags\0000\0queue_id\00067C9"..., 370) = 370
poll([{fd=16, events=POLLIN}], 1, 3600000) = 1 ([{fd=16,
revents=POLLIN|POLLHUP}])
read(16, 0x7f4e5a2cc020, 4096) = -1 EACCES (Permission denied)
close(16) = 0
sendto(7, "<20>Feb 14 23:35:37 postfix/smtp"..., 81, MSG_NOSIGNAL,
NULL, 0) = 81
sendto(7, "<22>Feb 14 23:35:37 postfix/smtp"..., 204, MSG_NOSIGNAL,
NULL, 0) = 204
rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
write(15,
"\27\3\3\0@\274\263\16I\316\343h\236\343\1\370\25\250}`\205\3110T\300\237uv\246\334\2470"..., 69) =
69
read(15, 0x7f4e5a2bf343, 5) = -1 EAGAIN (Resource
temporarily unavailable)
poll([{fd=15, events=POLLIN}], 1, 20000) = 1 ([{fd=15, revents=POLLIN}])
read(15, "\27\3\3\0P", 5) = 5
read(15,
"\266\2315\33\336\320\233\213\342\177\235\353\0=8?\215`\331\347\224\1\332\262wtS#\223\25-/"..., 80) =
80
write(15,
"\25\3\3\0000\222\236\22\327\204D\37i\364\rM\327#\276H\356\346{\263~\200'i\313\374\357\243"..., 53) =
53
read(15, "\25\3\3\0000", 5) = 5
read(15,
"\363\362d\263r\336;\17H\363\300c\236\231%=\360\260\321\263\330\270v\314\6\220>\307\300Q\6j"..., 48) =
48
close(15) = 0
poll([{fd=13, events=POLLOUT}], 1, 3600000) = 1 ([{fd=13, revents=POLLOUT}])
write(13, "status\0\0diag_type\0\0diag_text\0\0mt"..., 86) = 86
poll([{fd=13, events=POLLIN}], 1, 3600000) = 1 ([{fd=13,
revents=POLLIN|POLLHUP}])
read(13, "", 4096) = 0
close(14) = 0
close(13) = 0
write(5, "\243$\0\0\353\1\0\0\1\0\0\0", 12) = 12
alarm(0) = 6000
flock(8, LOCK_EX) = 0
alarm(6000) = 0
epoll_wait(10, {}, 100, 5000) = 0
epoll_ctl(10, EPOLL_CTL_DEL, 9, {EPOLLIN, {u32=9,
u64=6302269001074475017}}) = 0
close(9) = 0
alarm(0) = 5995
flock(8, LOCK_EX) = 0
alarm(6000) = 0
epoll_wait(10, {}, 100, 95000) = 0
exit_group(0) = ?
+++ exited with 0 +++
Quoting Viktor Dukhovni <postfix-us...@dukhovni.org>:
On Sat, Feb 14, 2015 at 03:30:45PM -0500, Wietse Venema wrote:
In conclusion, whatever the problem is, it is not in Postfix. My
test shows that it works fine in a non-container environment on what
should basically be the same kernel as what you use.
An "strace" of an smtp(8) delivery agent failing to receive the
bounce(8) service reply might shed a bit more light on the kernel
issue.
http://www.postfix.org/DEBUG_README.html#auto_trace
master.cf:
127.0.0.1:52 inet n - n - - smtpd
-o smtpd_client_restrictions=reject
debug unix - - n - - smtp -D
main.cf:
indexed = ${default_database_type}:${config_directory}/
transport_maps = ${indexed}transport
debugger_command =
PATH=/bin:/usr/bin:/sbin:/usr/sbin;
(strace -p $process_id -o ${queue_directory}/trace.$process_id)
& sleep 2
transport:
debu...@example.net debug:[127.0.0.1]:52
Send a single message to debu...@example.com, and post the resulting
trace file, which will be in the Postfix queue directory.
You can trim off the top of the trace file above the connect to
the bounce socket (/var/spool/postfix/private/bounce).
--
Viktor.
