- 论坛徽章:
- 0
|
为了找到这个问题,我吧amavis的日志开到5,等待问题再次发生。
果然昨天又发生了,下面是日志
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) File-type of p003: Microsoft Office Document; (doc)
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) result line from file(1): p004: ASCII text\n
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) lookup_re("ASCII text") matches key "(?i-xsm:^(ASCII|text)\b)", result="asc"
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) lookup [map_full_type_to_short_type] => true, "ASCII text" matches, result="asc", matching_key="(?i-xsm:^(ASC
- II|text)\\b)"
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) File-type of p004: ASCII text; (asc)
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) decompose_part: p001 - atomic
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) decompose_part: p002 - atomic
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) decompose_part: p003 - atomic
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) do_ascii: Decoding part p004
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) do_ascii: Setting sigaction handler, was 0
- Oct 20 05:55:55 mail amavis[13401]: (13401-02) timer set to 320 s (was 480 s)
- Oct 20 05:55:55 mail amavis[23606]: Net::Server: Starting "1" children
- Oct 20 05:55:55 mail amavis[13583]: Net::Server: Child Preforked (13583)
- Oct 20 05:55:55 mail amavis[13583]: entered child_init_hook
- Oct 20 05:55:55 mail postfix/smtp[13580]: 08EBAF27008E: to=<reserved@****.com>, orig_to=<reserved@****.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=118011, delays=118011/0.01/0/0.09, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent morethan once)
- Oct 20 05:55:55 mail postfix/smtp[13580]: 08EBAF27008E: to=<tao@****.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=118011, delays=118011/0.01/0/0.09, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once)
- Oct 20 05:55:55 mail amavis[13583]: (!!)TROUBLE in child_init_hook: BDB no dbS: Unknown locker ID: 5dd, . at (eval 79) line 27.
- Oct 20 05:55:55 mail amavis[13583]: (!)_DIE: Suicide in child_init_hook: BDB no dbS: Unknown locker ID: 5dd, . at (eval 79) line 27.
- Oct 20 05:55:55 mail amavis[23606]: Net::Server: Starting "1" children
- Oct 20 05:55:55 mail amavis[13585]: Net::Server: Child Preforked (13585)
- Oct 20 05:55:55 mail amavis[13585]: entered child_init_hook
- Oct 20 05:55:55 mail amavis[13585]: (!!)TROUBLE in child_init_hook: BDB no dbS: Unknown locker ID: 5de, . at (eval 79) line 27.
- Oct 20 05:55:55 mail amavis[13585]: (!)_DIE: Suicide in child_init_hook: BDB no dbS: Unknown locker ID: 5de, . at (eval 79) line 27.
- Oct 20 05:55:55 mail amavis[23606]: Net::Server: Starting "1" children
- Oct 20 05:55:55 mail amavis[13586]: Net::Server: Child Preforked (13586)
- Oct 20 05:55:55 mail amavis[13586]: entered child_init_hook
- Oct 20 05:55:55 mail amavis[13586]: (!!)TROUBLE in child_init_hook: BDB no dbS: Unknown locker ID: 5df, . at (eval 79) line 27.
- Oct 20 05:55:55 mail amavis[13586]: (!)_DIE: Suicide in child_init_hook: BDB no dbS: Unknown locker ID: 5df, . at (eval 79) line 27.
- Oct 20 05:55:55 mail amavis[23606]: Net::Server: Starting "1" children
- Oct 20 05:55:55 mail amavis[13587]: Net::Server: Child Preforked (13587)
- Oct 20 05:55:55 mail amavis[13587]: entered child_init_hook
复制代码
在出错前,有这个问题
lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once
服务器在127.0.0.1 的地址上有 amavis的10024和10025 还有slockd的 10030 ,但是感觉问题应该是在amavis上链接错误的问题。
刚才查了queue也有几封邮件是这个问题在队列里停着,用 postqueue -i 重新发送也无法发送。
下面是重发时的日志
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) Extracting mime components
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) Issued a new file name: p001
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) Charging 668 bytes to remaining quota 1444000 (out of 1444000, (0%)) - by mime_decode
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) p001 1 Content-Type: text/plain, size: 668 B, name:
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) prolong_timer mime_decode: remaining time = 480 s
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) prolong_timer mime_decode-1: remaining time = 480 s
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) decode_parts: level=1, #parts=1 : p001
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) running file(1) on 1 files, arglist size 18
- Oct 20 16:59:50 mail amavis[19849]: (17963-11) open_on_specific_fd: target fd0 closing, to become < /dev/null
- Oct 20 16:59:50 mail amavis[19849]: (17963-11) open_on_specific_fd: target fd1 closing, to become > &=15
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) run_command: [19849] /usr/bin/file p001 </dev/null 2>&1
- Oct 20 16:59:50 mail amavis[19849]: (17963-11) open_on_specific_fd: target fd1 dup2 from fd15 > &=15
- Oct 20 16:59:50 mail amavis[19849]: (17963-11) open_on_specific_fd: source fd15 closed
- Oct 20 16:59:50 mail amavis[19849]: (17963-11) open_on_specific_fd: target fd2 closing, to become > &1
- Oct 20 16:59:50 mail amavis[19849]: (17963-11) open_on_specific_fd: target fd2 dup2 from fd1 > &1
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) result line from file(1): p001: UTF-8 Unicode mail text\n
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) lookup_re("UTF-8 Unicode mail text") matches key "(?i-xsm:\btext\b)", result="asc"
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) lookup [map_full_type_to_short_type] => true, "UTF-8 Unicode mail text" matches, result="asc", matching_key="(?i-xsm:\\btext\\b)"
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) File-type of p001: UTF-8 Unicode mail text; (asc)
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) do_ascii: Decoding part p001
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) do_ascii: Setting sigaction handler, was 0
- Oct 20 16:59:50 mail amavis[17963]: (17963-11) timer set to 320 s (was 480 s)
- Oct 20 16:59:50 mail amavis[11441]: Net::Server: Starting "1" children
- Oct 20 16:59:50 mail amavis[19851]: Net::Server: Child Preforked (19851)
- Oct 20 16:59:50 mail amavis[19851]: entered child_init_hook
- Oct 20 16:59:50 mail postfix/smtp[19788]: 61DA0F270058: to=<yao@****.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=107949, delays=107949/0/0/0.06, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending end of data -- message may be sent more than once)
复制代码
然后立即在服务器上链接localhost 的10024 ,ehlo localhost 后能正常显示信息。不过速度偏慢,有5-10秒延迟。
有检查了perl 的 db模块是Module BerkeleyDB 0.39 在cpan上是最新的版本没有什么可以升级的。
感觉是不是那个127.0.0.1出问题了,但日志也看不出来。
不知道哪位高人碰到过。 |
|