Re: [AMaViS-user] SQL Error - same problems here

SourceForge Headquarters 225 Broadway Suite 1600 San Diego, CA 92101 +1 (858) 454-5900

Markus Edholm wrote:
> ".....
> 
> Mail.err:
> 
> May 11 17:29:22 localhost amavis[22607]: (22607-07-4) (!!)TROUBLE in 
> check_mail: quar+notif FAILED: temporarily unable to quarantine: 451 
> 4.5.0 Storing to sql db as mail_id X97DK1raAEHO failed: writing mail 
> text to SQL failed: Error closing, flush: sql inserting text failed, sql 
> exec: err=1452, S1000, DBD::mysql::st execute failed: Cannot add or 
> update a child row: a foreign key constraint fails 
> (`amavisd/quarantine`, CONSTRAINT `quarantine_ibfk_1` FOREIGN KEY 
> (`mail_id`) REFERENCES `msgs` (`mail_id`) ON DELETE CASCADE) at (eval 
> 43) line 162, <GEN115> line 236. at (eval 47) line 196, <GEN115> line 
> 236. at (eval 47) line 78, <GEN115> line 236. at (eval 47) line 322, 
> <GEN115> line 236., id=22607-07-4 at /usr/sbin/amavisd-new line 10056, 
> <GEN115> line 236.
 > ....."

I have to report same problems. this has happened with few e-mails on 2 
totally unrelated servers. Servers are configured similarly, however. 
Both are CentOS 4.4 , SA 3.2, amavisd-new 2.5.0, 
mysql-server-4.1.20-2.RHEL4.1, F-Secure AV

Symptoms appeared after upgrading SA to 3.2, and amavisd-new from 2.4.5 
to 2.5.0. After switching back to amavisd-new 2.4.5, this problem went away.

Here's the amavisd-new log output form one server (domain names replaced 
with "repalceddomain"):

May 13 14:47:42 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) ESMTP::10024 /var/amavis/tmp/amavis-20070513T144723-08145: 
<> -> <dvastarchy@replaceddomain_2.ee> SIZE=4607 Received: from 
gw.replaceddomain_1.ee ([127.0.0.1]) by localhost 
(gw.replaceddomain_1.ee [127.0.0.1]) (amavisd-new, port 10024) with 
ESMTP for <dvastarchy@replaceddomain_2.ee>; Sun, 13 May 2007 14:47:42 
+0300 (EEST)
May 13 14:47:42 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) body hash: ae4e38ce640015c94a89cdd693c3eb80
May 13 14:47:42 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) Checking: zImQpnXECCCl [222.146.40.211] <> -> 
<dvastarchy@replaceddomain_2.ee>
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) 2822.From: <MAI...@mf...>, 
2821.Mail_From: <>
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) p004 1 Content-Type: multipart/report
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) p001 1/1 Content-Type: text/plain, size: 1056 B, name:
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) p002 1/2 Content-Type: message/delivery-status, size: 394 
B, name:
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) p005 1/3 Content-Type: message/rfc822
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) p003 1/3/1 Content-Type: text/plain, size: 880 B, name:
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) Checking for banned types and filenames
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) collect banned table[0]: dvastarchy@replaceddomain_2.ee, 
tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x93611a0)
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) p.path dvastarchy@replaceddomain_2.ee: 
"P=p004,L=1,M=multipart/report | P=p001,L=1/1,M=text/plain,T=asc"
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) p.path dvastarchy@replaceddomain_2.ee: 
"P=p004,L=1,M=multipart/report | 
P=p002,L=1/2,M=message/delivery-status,T=asc"
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) p.path dvastarchy@replaceddomain_2.ee: 
"P=p004,L=1,M=multipart/report | P=p005,L=1/3,M=message/rfc822 | 
P=p003,L=1/3/1,M=text/plain,T=asc"
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) Using (F-Secure Antivirus for Linux servers): 
/opt/f-secure/fsav/bin/fsav 
--configfile=/opt/f-secure/fsav/etc/fsav.conf --delete=no --disinf=no 
--rename=no --archive=yes --auto=yes --dumb=yes --list=no --mime=yes 
/var/amavis/tmp/amavis-20070513T144723-08145/parts
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) run_av: /opt/f-secure/fsav/bin/fsav exit 0, F-Secure 
Anti-Virus for Linux Gateways version 4.65  build 5446\nCopyright (c) 
1999-2004 F-Secure Corporation. All Rights Reserved.\n\nScan started at 
Sun 13 May 2007 02:47:43 PM EEST\nDatabase version: 
2007-05-11_04\n\n\nScan ended at Sun 13 May 2007 02:47:43 PM EEST\n3 
files scanned
May 13 14:47:43 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) run_av (F-Secure Antivirus for Linux servers): CLEAN
May 13 14:47:46 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) spam_scan: score=12.523 autolearn=spam 
tests=[AWL=-2.357,BAYES_99=5.9,RAZOR2_CF_RANGE_51_100=2,RAZOR2_CF_RANGE_E4_51_100=1.5,RAZOR2_CHECK=4,SARE_MLB_Stock1=1.48]
May 13 14:47:46 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) blocking contents category is (6) for 
dvastarchy@replaceddomain_2.ee
May 13 14:47:46 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) do_notify_and_quar: ccat=Spam (6,0) ("6":Spam, "5":Spammy, 
"1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(6), q_mth=sql:, 
qar_mth=
May 13 14:47:46 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) SEND via SQL 
(DBI:mysql:database=mail;host=127.0.0.1;port=3306): <> -> 
<dvastarchy@replaceddomain_2.ee>, mail_id zImQpnXECCCl
May 13 14:47:46 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) writing mail text to SQL failed: Error closing, flush: sql 
inserting text failed, sql exec: err=1216, S1000, DBD::mysql::st execute 
failed: Cannot add or update a child row: a foreign key constraint fails 
at (eval 67) line 162, <GEN10> line 1432. at (eval 69) line 196, <GEN10> 
line 1432. at (eval 69) line 78, <GEN10> line 1432.
May 13 14:47:46 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) mail_via_sql: rollback done
May 13 14:47:46 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) (!!)TROUBLE in check_mail: quar+notif FAILED: temporarily 
unable to quarantine: 451 4.5.0 Storing to sql db as mail_id 
zImQpnXECCCl failed: writing mail text to SQL failed: Error closing, 
flush: sql inserting text failed, sql exec: err=1216, S1000, 
DBD::mysql::st execute failed: Cannot add or update a child row: a 
foreign key constraint fails at (eval 67) line 162, <GEN10> line 1432. 
at (eval 69) line 196, <GEN10> line 1432. at (eval 69) line 78, <GEN10> 
line 1432. at (eval 69) line 322., id=08145-02-6 at 
/usr/local/sbin/amavisd line 10056.
May 13 14:47:46 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) (!)PRESERVING EVIDENCE in 
/var/amavis/tmp/amavis-20070513T144723-08145
May 13 14:47:46 gw.replaceddomain_1.ee /usr/local/sbin/amavisd[8145]: 
(08145-02-6) TIMING [total 3566 ms] - SMTP pre-DATA-flush: 4 (0%)0, SMTP 
DATA: 75 (2%)2, check_init: 1 (0%)2, digest_hdr: 1 (0%)2, digest_body: 1 
(0%)2, sql-enter: 4 (0%)2, mime_decode: 37 (1%)3, get-file-type3: 92 
(3%)6, decompose_part: 2 (0%)6, decompose_part: 1 (0%)6, decompose_part: 
1 (0%)6, parts_decode: 0 (0%)6, check_header: 3 (0%)6, AV-scan-1: 65 
(2%)8, spam-wb-list: 3 (0%)8, SA msg read: 2 (0%)8, SA parse: 5 (0%)8, 
SA check: 3231 (91%)99, update_cache: 9 (0%)99, penpals_check: 0 (0%)99, 
decide_mail_destiny: 3 (0%)99, write-header: 10 (0%)100, fwd-sql: 13 
(0%)100, SMTP pre-response: 1 (0%)100, SMTP response: 1 (0%)100, 
rundown: 1 (0%)100

Vahur