From: Pavel Urban (no email)
Date: Tue Sep 07 2004 - 05:22:29 EDT
Victor Duchovni wrote:
> On Wed, Sep 01, 2004 at 10:06:48AM +0200, Pavel Urban wrote:
>
>
>>>Hello,
>>>
>>
>>>from time to time, these lines appear in my logs:
>>
>>>Aug 31 00:44:29 smtp-out1 postfix/qmgr[23779]: warning: premature
>>>end-of-input on private/smtp socket while reading input attribute name
>>>Aug 31 00:44:29 smtp-out1 postfix/qmgr[23779]: warning: private/smtp
>>>socket: malformed response
>>>Aug 31 00:44:29 smtp-out1 postfix/qmgr[23779]: warning: transport smtp
>>>failure -- see a previous warning/fatal/panic logfile record for the
>>>problem description
>>>Aug 31 00:44:29 smtp-out1 postfix/master[23775]: warning: process
>>>/usr/libexec/postfix/smtp pid 13121 killed by signal 6
>>>
>>>Seems like smtp process is dying with signal 6 or 11. That is strange,
>>>because it happens on two machines that were running previous versions
>>>happily, without problem. Is it possible to instruct Postfix to dump
>>>core? Or can you suggest another debugging method? The problem is that
>>>these machines are quite loaded and the problem occures infrequently.
>>>
>>>My system is RH Linux 3 ES, Postfix re-compiled from S.J.Mudd's SRPM,
>>>version 2.1.3-2, with pcre, sasl2 and tls support (I know that this is
>>>not 'officialy' supported...)
>>>
>>
>>Too bad, the newest RPM exhibits the same behaviour. Anybody else seen
>>problems with TLS-enabled Postfix on RH ES 3?
>>
>
>
> The only way to get at the real problem is to get a stack trace.
>
> http://www.postfix.org/DEBUG_README.html
> http://www.postfix.org/postconf.5.html#debugger_command
>
> read about the "-D" switch, some familiarity with Unix debuggers
> required...
>
I've tried 'strace' instead of gdb, but I don't feel any smarter :-(
Please, take a look at the part of my log and tell me what do you think
about it. Thanks!
[root at aphrael pos]# tail -100 debug-4079
send(12, "\'\320\1\0\0\1\0\0\0\0\0\0\7prodigy\3net\0\0\17\0\1", 29, 0) = 29
gettimeofday({1094548039, 107773}, NULL) = 0
poll([{fd=12, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(12,
"\'\320\201\200\0\1\0\6\0\3\0\t\7prodigy\3net\0\0\17\0\1"..., 4096, 0,
{sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, [16]) = 366
close(12) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 12
connect(12, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, 28) = 0
send(12, "\'\321\1\0\0\1\0\0\0\0\0\0\3mx6\7prodigy\3net\0\0\1\0"..., 33,
0) = 33
gettimeofday({1094548039, 109782}, NULL) = 0
poll([{fd=12, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(12,
"\'\321\201\200\0\1\0\1\0\3\0\3\3mx6\7prodigy\3net\0\0\1"..., 4096, 0,
{sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, [16]) = 170
close(12) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 12
connect(12, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, 28) = 0
send(12, "\'\322\1\0\0\1\0\0\0\0\0\0\3mx1\7prodigy\3net\0\0\1\0"..., 33,
0) = 33
gettimeofday({1094548039, 111813}, NULL) = 0
poll([{fd=12, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(12,
"\'\322\201\200\0\1\0\1\0\3\0\3\3mx1\7prodigy\3net\0\0\1"..., 4096, 0,
{sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, [16]) = 170
close(12) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 12
connect(12, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, 28) = 0
send(12, "\'\323\1\0\0\1\0\0\0\0\0\0\3mx2\7prodigy\3net\0\0\1\0"..., 33,
0) = 33
gettimeofday({1094548039, 112974}, NULL) = 0
poll([{fd=12, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(12,
"\'\323\201\200\0\1\0\1\0\3\0\3\3mx2\7prodigy\3net\0\0\1"..., 4096, 0,
{sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, [16]) = 170
close(12) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 12
connect(12, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, 28) = 0
send(12, "\'\324\1\0\0\1\0\0\0\0\0\0\3mx3\7prodigy\3net\0\0\1\0"..., 33,
0) = 33
gettimeofday({1094548039, 114944}, NULL) = 0
poll([{fd=12, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(12,
"\'\324\201\200\0\1\0\1\0\3\0\3\3mx3\7prodigy\3net\0\0\1"..., 4096, 0,
{sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, [16]) = 170
close(12) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 12
connect(12, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, 28) = 0
send(12, "\'\325\1\0\0\1\0\0\0\0\0\0\3mx4\7prodigy\3net\0\0\1\0"..., 33,
0) = 33
gettimeofday({1094548039, 115964}, NULL) = 0
poll([{fd=12, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(12,
"\'\325\201\200\0\1\0\1\0\3\0\3\3mx4\7prodigy\3net\0\0\1"..., 4096, 0,
{sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, [16]) = 170
close(12) = 0
socket(PF_INET, SOCK_DGRAM, IPPROTO_IP) = 12
connect(12, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, 28) = 0
send(12, "\'\326\1\0\0\1\0\0\0\0\0\0\3mx5\7prodigy\3net\0\0\1\0"..., 33,
0) = 33
gettimeofday({1094548039, 117498}, NULL) = 0
poll([{fd=12, events=POLLIN, revents=POLLIN}], 1, 5000) = 1
recvfrom(12,
"\'\326\201\200\0\1\0\1\0\3\0\3\3mx5\7prodigy\3net\0\0\1"..., 4096, 0,
{sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("192.168.30.22")}, [16]) = 170
close(12) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 12
fcntl64(12, F_GETFL) = 0x2 (flags O_RDWR)
fcntl64(12, F_SETFL, O_RDWR|O_NONBLOCK) = 0
connect(12, {sa_family=AF_INET, sin_port=htons(25),
sin_addr=inet_addr("207.115.57.15")}, 16) = -1 EINPROGRESS (Operation
now in progress)
select(13, NULL, [12], [12], {30, 0}) = 1 (out [12], left {29, 890000})
getsockopt(12, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
fcntl64(12, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
fcntl64(12, F_SETFL, O_RDWR) = 0
select(13, [12], NULL, [12], {300, 0}) = 1 (in [12], left {299, 880000})
read(12, "220 ylpvm16.prodigy.net ESMTP Se"..., 4096) = 95
time(NULL) = 1094548039
time(NULL) = 1094548039
time(NULL) = 1094548039
select(13, NULL, [12], [12], {300, 0}) = 1 (out [12], left {300, 0})
write(12, "EHLO smtp-out1.iol.cz\r\n", 23) = 23
time(NULL) = 1094548039
select(13, [12], NULL, [12], {300, 0}) = 1 (in [12], left {299, 880000})
read(12, "250-ylpvm16.prodigy.net Hello sm"..., 4096) = 109
time(NULL) = 1094548039
time(NULL) = 1094548039
select(13, NULL, [12], [12], {300, 0}) = 1 (out [12], left {300, 0})
write(12, "MAIL FROM:<>\r\n", 30) = 30
time(NULL) = 1094548039
select(13, [12], NULL, [12], {300, 0}) = 1 (in [12], left {299, 890000})
read(12, "451 4.7.7 Excessive userid unkno"..., 4096) = 55
time([1094548039]) = 1094548039
getpid() = 4079
rt_sigaction(SIGPIPE, {0xb72905e0, [], SA_RESTORER, 0xb71dfde8},
{SIG_IGN}, 8) = 0
send(7, "<182>Sep 7 11:07:19 postfix/smt"..., 181, 0) = 181
rt_sigaction(SIGPIPE, {SIG_IGN}, NULL, 8) = 0
time(NULL) = 1094548039
time(NULL) = 1094548039
select(13, NULL, [12], [12], {120, 0}) = 1 (out [12], left {120, 0})
write(12, "RSET\r\n", 6) = 6
time(NULL) = 1094548039
select(13, [12], NULL, [12], {120, 0}) = 1 (in [12], left {119, 890000})
read(12, "250 2.0.0 Reset state\r\n", 4096) = 23
time(NULL) = 1094548039
time(NULL) = 1094548039
select(13, NULL, [12], [12], {120, 0}) = 1 (out [12], left {120, 0})
write(12, "QUIT\r\n", 6) = 6
close(12) = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 12
fcntl64(12, F_GETFL) = 0x2 (flags O_RDWR)
fcntl64(12, F_SETFL, O_RDWR|O_NONBLOCK) = 0
connect(12, {sa_family=AF_INET, sin_port=htons(25),
sin_addr=inet_addr("207.115.63.85")}, 16) = -1 EINPROGRESS (Operation
now in progress)
select(13, NULL, [12], [12], {30, 0}) = 1 (out [12], left {29, 890000})
getsockopt(12, SOL_SOCKET, SO_ERROR, [0], [4]) = 0
fcntl64(12, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
fcntl64(12, F_SETFL, O_RDWR) = 0
select(13, [12], NULL, [12], {300, 0}) = 1 (in [12], left {299, 870000})
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
Process 4079 detached
P.U.
|
|
|