On Fri, Sep 26, 2014 at 12:50:47PM +0000, Viktor Dukhovni wrote:
>
> Can you provide a bit more context from that trace. Replace the "..." with
> 20 or so more lines above the "flock(21, LOCK_UN)"
Yes, sorry for the delay; had to re-run it. Does this provide enough
context (from MAIL FROM):
10:31:44.127907 read(9, "MAIL FROM:<sen...@example.com>\r\n", 4096) = 29
<0.000011>
10:31:44.127983 socket(PF_FILE, SOCK_STREAM, 0) = 13 <0.000013>
10:31:44.128021 fcntl(13, F_GETFL) = 0x2 (flags O_RDWR) <0.000008>
10:31:44.128055 fcntl(13, F_SETFL, O_RDWR) = 0 <0.000008>
10:31:44.128081 connect(13, {sa_family=AF_FILE, path="private/rewrite"}, 110) =
0 <0.000097>
10:31:44.128218 fcntl(13, F_GETFD) = 0 <0.000020>
10:31:44.128258 fcntl(13, F_SETFD, FD_CLOEXEC) = 0 <0.000008>
10:31:44.128286 epoll_ctl(12, EPOLL_CTL_ADD, 13, {EPOLLIN, {u32=13,
u64=5116440436298219533}}) = 0 <0.000008>
10:31:44.128320 poll([{fd=13, events=POLLOUT}], 1, 3600000) = 1 ([{fd=13,
revents=POLLOUT}]) <0.000009>
10:31:44.128354 write(13,
"request\0rewrite\0rule\0local\0address\0sen...@example.com\0\0", 52) = 52
<0.000013>
10:31:44.128412 poll([{fd=13, events=POLLIN}], 1, 3600000) = 1 ([{fd=13,
revents=POLLIN}]) <0.000009>
10:31:44.128454 read(13, "flags\0000\0address\0sen...@example.com\0\0", 4096) =
33 <0.000012>
10:31:44.128500 poll([{fd=13, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000008>
10:31:44.128533 poll([{fd=13, events=POLLOUT}], 1, 3600000) = 1 ([{fd=13,
revents=POLLOUT}]) <0.000008>
10:31:44.128563 write(13,
"request\0resolve\0sender\0\0address\0sen...@example.com\0\0", 49) = 49
<0.000012>
10:31:44.128607 poll([{fd=13, events=POLLIN}], 1, 3600000) = 1 ([{fd=13,
revents=POLLIN}]) <0.002610>
10:31:44.131256 read(13,
"flags\0000\0transport\0local\0nexthop\0hostname.example.com\0recipient\0sen...@example.com\0flags\000256\0\0",
4096) = 88 <0.000012>
10:31:44.131328 statfs(".", {f_type="EXT2_SUPER_MAGIC", f_bsize=4096,
f_blocks=51606190, f_bfree=50920517, f_bavail=48299078, f_files=13107200,
f_ffree=13099659, f_fsid={-2033665112, 1815498530}, f_namelen=255,
f_frsize=4096}) = 0 <0.000012>
10:31:44.131381 stat(".", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
<0.000010>
10:31:44.131437 poll([{fd=9, events=POLLOUT}], 1, 120000) = 1 ([{fd=9,
revents=POLLOUT}]) <0.000009>
10:31:44.131471 write(9, "250 2.1.0 Ok\r\n", 14) = 14 <0.000017>
10:31:44.131511 poll([{fd=9, events=POLLIN}], 1, 120000) = 1 ([{fd=9,
revents=POLLIN}]) <9.318293>
10:31:53.449846 read(9, "RCPT TO:<recipi...@example.com>\r\n", 4096) = 31
<0.000013>
10:31:53.450427 poll([{fd=13, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000009>
10:31:53.450462 poll([{fd=13, events=POLLOUT}], 1, 3600000) = 1 ([{fd=13,
revents=POLLOUT}]) <0.000009>
10:31:53.450493 write(13,
"request\0rewrite\0rule\0local\0address\0recipi...@example.com\0\0", 56) = 56
<0.000013>
10:31:53.450550 poll([{fd=13, events=POLLIN}], 1, 3600000) = 1 ([{fd=13,
revents=POLLIN}]) <0.000010>
10:31:53.450603 read(13, "flags\0000\0address\0recipi...@example.com\0\0",
4096) = 37 <0.000012>
10:31:53.450651 poll([{fd=13, events=POLLIN}], 1, 0) = 0 (Timeout) <0.000009>
10:31:53.450689 poll([{fd=13, events=POLLOUT}], 1, 3600000) = 1 ([{fd=13,
revents=POLLOUT}]) <0.000011>
10:31:53.450736 write(13,
"request\0resolve\0sender\0\0address\0recipi...@example.com\0\0", 53) = 53
<0.000078>
10:31:53.450858 poll([{fd=13, events=POLLIN}], 1, 3600000) = 1 ([{fd=13,
revents=POLLIN}]) <0.002264>
10:31:53.453159 read(13,
"flags\0000\0transport\0local\0nexthop\0hostname.example.com\0recipient\0recipi...@example.com\0flags\000256\0\0",
4096) = 92 <0.000025>
10:31:53.453244 flock(21, LOCK_SH) = 0 <0.000010>
10:31:53.453288 flock(21, LOCK_UN) = 0 <0.000010>
10:31:53.453319 flock(21, LOCK_SH) = 0 <0.000009>
10:31:53.453352 flock(21, LOCK_UN) = 0 <0.000009>
10:31:53.453381 flock(21, LOCK_SH) = 0 <0.000009>
10:31:53.453413 flock(21, LOCK_UN) = 0 <0.000022>
10:31:53.453455 flock(21, LOCK_SH) = 0 <0.000008>
10:31:53.453485 flock(21, LOCK_UN) = 0 <0.000008>
10:31:53.453525 flock(21, LOCK_SH) = 0 <0.000008>
10:31:53.453554 flock(21, LOCK_UN) = 0 <0.000008>
10:31:53.453580 flock(21, LOCK_SH) = 0 <0.000009>
10:31:53.453609 flock(21, LOCK_UN) = 0 <0.000008>
10:31:53.453635 flock(21, LOCK_SH) = 0 <0.000008>
10:31:53.453664 flock(21, LOCK_UN) = 0 <0.000008>
10:31:53.453735 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0 <0.000009>
10:31:53.453774 rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0 <0.000011>
10:31:53.453813 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000008>
10:31:53.453841 nanosleep({1, 0}, 0x7fffa29253c0) = 0 <1.000073>
10:31:54.453978 flock(23, LOCK_SH) = 0 <0.000011>
10:31:54.454030 flock(23, LOCK_UN) = 0 <0.000010>
10:31:54.454062 flock(23, LOCK_SH) = 0 <0.000009>
10:31:54.454096 flock(23, LOCK_UN) = 0 <0.000009>
10:31:54.454139 flock(23, LOCK_SH) = 0 <0.000008>
10:31:54.454171 flock(23, LOCK_UN) = 0 <0.000021>
10:31:54.454213 flock(23, LOCK_SH) = 0 <0.000009>
10:31:54.454260 flock(23, LOCK_UN) = 0 <0.000009>
10:31:54.454304 flock(27, LOCK_SH) = 0 <0.000010>
