Hi I'm administering a RH9-based mail system (sendmail ver. 8.12.11 rel. 4.24.1.legacy ) with more than 10k mailboxes, and a 2+ years happy amavisd-new user. But now I upgraded my system (a whole yum update) and amavisd-new stopped working. I was running amavisd-new-20030616, and perl was among the updated packages, so I thought it was related to running and old version of amavisd-new. So we upgraded amavisd-new to 2.3.0, but the same errors continued to show up. We get an error on the maillog stating some problems after executing /usr/bin/file: Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) run_command: [2129] /usr/bin/file p001 p002 </dev/null 2>&1 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) TROUBLE in check_mail: mime_decode-1 FAILED: parsing file(1) results - missing last 2 results at (eval 41) line 156. Any clue? We checked file and execution permitions of directories and file, and everything seems to be OK. Executing the file command with the amavisd generated tempfile works. More logs on the bottom. Thanks. Jose I. Callero
A short version: ------------------8<--------------------------------------------------------- Apr 20 16:04:47 vmail-av1 sendmail[2085]: k3KJ4kvU002085: from=<[EMAIL PROTECTED]>, size=4604, class=0, nrcpts=1, msgid=<[EMAIL PROTECTED]>, proto=ESMTP, daemon=MTA, relay=vhosts4.montevideo.net.uy [200.40.50.174] Apr 20 16:04:47 vmail-av1 amavis[26883]: preprocess_policy_query: opening mail '/var/amavis/amavis-milter-k3KJ4kvU002085/email.txt' Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) AM.CL /var/amavis/amavis-milter-k3KJ4kvU002085: <[EMAIL PROTECTED]> -> <[EMAIL PROTECTED]> Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) AM.PDP: tempdir is to be PRESERVED: /var/amavis/amavis-milter-k3KJ4kvU002085 Apr 20 16:04:47 vmail-av1 amavis-milter[26544]: k3KJ4kvU002085: (mlfi_eom) TEMPFAIL, retval is 75 Apr 20 16:04:47 vmail-av1 sendmail[2085]: k3KJ4kvU002085: to=<[EMAIL PROTECTED]>, delay=00:00:00, pri=34604, stat=Please try again later ------------------8<--------------------------------------------------------- An extended log without sendmail: ------------------8<--------------------------------------------------------- Apr 20 16:04:47 vmail-av1 amavis[26883]: loaded base policy bank Apr 20 16:04:47 vmail-av1 amavis[26883]: prolong_timer after new request - timer reset: remaining time = 480 s Apr 20 16:04:47 vmail-av1 amavis[26883]: process_request: suggested_protocol="" on UNIX Apr 20 16:04:47 vmail-av1 amavis[26883]: preprocess_policy_query: opening mail '/var/amavis/amavis-milter-k3KJ4kvU002085/email.txt' Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) AM.CL /var/amavis/amavis-milter-k3KJ4kvU002085: <[EMAIL PROTECTED]> -> <[EMAIL PROTECTED]> Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) lookup (debug_sender) => undef, "[EMAIL PROTECTED]" does not match Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) check_mail_begin_task: 1 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) body hash: 17f66687faf40f94d5f9a687819acefc Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) Original mail size: 4785; quota set to: 2392500 bytes Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) Checking: sHOm8TUow6lY <[EMAIL PROTECTED]> -> <[EMAIL PROTECTED]> Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) query_keys: [EMAIL PROTECTED], ctorres@, aguasdelacosta.com.uy, .aguasdelacosta.com.uy, .com.uy, .uy, . Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) lookup_hash([EMAIL PROTECTED]), no matches Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) lookup (bypass_virus_checks) => undef, "[EMAIL PROTECTED]" does not match Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) Extracting mime components Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) Issued a new file name: p001 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) Issued a new file name: p002 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) mime_decode_preamble: 2 lines Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) Issued a new pseudo part: p003 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) p003 1 Content-Type: multipart/alternative Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) mime_decode_epilogue: 1 lines Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) Charging 818 bytes to remaining quota 2392500 (out of 2392500, (0%)) - by mime_decode Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) p001 1/1 Content-Type: text/plain, size: 818 B, name: Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) reparenting p001 from p000 to p003 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) Charging 2258 bytes to remaining quota 2391682 (out of 2392500, (0%)) - by mime_decode Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) p002 1/2 Content-Type: text/html, size: 2258 B, name: Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) reparenting p002 from p000 to p003 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) prolong_timer after mime_decode-1: remaining time = 480 s Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) decode_parts: level=1, #parts=3 : p001, p002, p003 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) run_command: [2129] /usr/bin/file p001 p002 </dev/null 2>&1 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) TROUBLE in check_mail: mime_decode-1 FAILED: parsing file(1) results - missing last 2 results at (eval 41) line 156. Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) AM.PDP: tempdir is to be PRESERVED: /var/amavis/amavis-milter-k3KJ4kvU002085 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) mail checking ended: setreply=451 4.5.0 Error%20in%20processing,%20id=26883, %20mime_decode-1%20FAILED: %20parsing%20file(1)%20results%20-%20missing%20last%202%20results%20at%20 (eval%2041)%20line%20156.\nreturn_value=tempfail\nexit_code=75 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) TIMING [total 136 ms] - got data: 9 (6%)6, body_hash: 10 (7%)14, gen_mail_id: 2 (1%)15, mkdir parts: 10 (7%)22, mime_decode: 66 (48%)70, rundown: 40 (30%)100 Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) post_process_request_hook: timer stopped Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) idle_proc, bye: was busy, 141.8 ms, total idle 0.000 s, busy 0.142 s Apr 20 16:04:47 vmail-av1 amavis[26883]: (26883) load: 100 %, total idle 0.000 s, busy 0.142 s Apr 20 16:04:47 vmail-av1 amavis-milter[26544]: k3KJ4kvU002085: (mlfi_eom) TEMPFAIL, retval is 75 Apr 20 16:04:48 vmail-av1 amavis-milter[26544]: k3KJ4mXV002150: (mlfi_eom) TEMPFAIL, retval is 75 Apr 20 16:04:49 vmail-av1 amavis[26883]: (26883) idle_proc, hi : was idle, 1687.6 ms, total idle 1.688 s, busy 0.142 s Apr 20 16:04:49 vmail-av1 amavis[26883]: (26883) loaded base policy bank Apr 20 16:04:49 vmail-av1 amavis[26883]: (26883) prolong_timer after new request - timer reset: remaining time = 480 s Apr 20 16:04:49 vmail-av1 amavis[26883]: (26883) process_request: suggested_protocol="" on UNIX ------------------------------------------------------- Using Tomcat but need to do more? Need to support web services, security? Get stuff done quickly with pre-integrated technology to make your job easier Download IBM WebSphere Application Server v.1.0.1 based on Apache Geronimo http://sel.as-us.falkag.net/sel?cmd=lnk&kid=120709&bid=263057&dat=121642 _______________________________________________ AMaViS-user mailing list AMaViS-user@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/amavis-user AMaViS-FAQ:http://www.amavis.org/amavis-faq.php3 AMaViS-HowTos:http://www.amavis.org/howto/
