1 Topic by leonnl

  • leonnl
  • Member
  • Offline
  • Registered: 2024-03-01
  • Posts: 4

Topic: A lot of clean email with low spam scores is quarantined

==== REQUIRED BASIC INFO OF YOUR IREDMAIL SERVER ====
- iRedMail version (check /etc/iredmail-release):  1.6.8 MARIADB edition
- Deployed with iRedMail Easy or the downloadable installer? installer
- Linux/BSD distribution name and version: AlmaLinux 8.9
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): SQL
- Web server (Apache or Nginx): nginx
- Manage mail accounts with iRedAdmin-Pro? yes
- [IMPORTANT] Related original log or error message is required if you're experiencing an issue.
====

This is a clean install of iRedMail/iRedAdmin-Pro-SQL, we copied over databases and /var/vmail
I have debugging enabled on amavis but I do not see anything weird apart from this:

....
Mar  1 15:13:24 ams amavis[47558]: (47558-01) blocking contents category is (6) for info@XXXX.nl, final_destiny 0
...
Mar  1 15:13:24 ams amavis[47558]: (47558-01) blocking ccat=6, SMTP response: 250 2.7.0 Ok, discarded, id=47558-01 - spam
Mar  1 15:13:24 ams amavis[47558]: (47558-01) do_notify_and_quar: ccat=Spam (6,0) ("6":Spam, "5,1":Spammy3, "5":Spammy, "1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(6), qar_mth=
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_quarantine_to) rec=0, "info@XXXX.nl" result: "spam-quarantine"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_quarantine_to] => true,  "info@XXXX.nl" matches, result="spam-quarantine", matching_key="/cached/"

The spam score for this email is very low:

X-Quarantine-ID: <zlF2hpQDNhMy>
X-Spam-Flag: YES
X-Spam-Score: 0.43
X-Spam-Level:
X-Spam-Status: Yes, score=0.43 tag=0 tag2=0 kill=0
    tests=[DKIMWL_WL_HIGH=-0.096, DKIM_SIGNED=0.1, DKIM_VALID=-0.1,
    DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, HTML_MESSAGE=0.001,
    HTML_MIME_NO_HTML_TAG=0.635, LOTS_OF_MONEY=0.001, MIME_HTML_ONLY=0.1,
    RCVD_IN_MSPIKE_H2=-0.001, SPF_HELO_PASS=-0.001, SPF_PASS=-0.001,
    T_SCC_BODY_TEXT_LINE=-0.01, URIBL_BLOCKED=0.001, URI_TRUNCATED=0.001]
    autolearn=no autolearn_force=no

Any pointers as to why such emails are being quarantined would be highly appreciated!

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2 Reply by leonnl

  • leonnl
  • Member
  • Offline
  • Registered: 2024-03-01
  • Posts: 4

Re: A lot of clean email with low spam scores is quarantined

Here is the full log entry (verbose level 5) in 2 parts;

Mar  1 15:13:22 ams postfix/postscreen[49490]: PASS NEW [50.31.156.122]:57679
Mar  1 15:13:22 ams postfix/smtpd[49499]: connect from sc-ord-mta122.mtasv.net[50.31.156.122]
Mar  1 15:13:22 ams postfix/smtpd[49499]: discarding EHLO keywords: CHUNKING
Mar  1 15:13:22 ams postfix/submission/smtpd[49495]: Anonymous TLS connection established from unknown[187.161.222.144]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Mar  1 15:13:22 ams postfix/smtpd[49499]: Anonymous TLS connection established from sc-ord-mta122.mtasv.net[50.31.156.122]: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256
Mar  1 15:13:22 ams postfix/smtpd[49499]: discarding EHLO keywords: CHUNKING
Mar  1 15:13:23 ams postfix/smtpd[49499]: 4TmVS308MWz2qDrL: client=sc-ord-mta122.mtasv.net[50.31.156.122]
Mar  1 15:13:23 ams postfix/cleanup[49507]: 4TmVS308MWz2qDrL: message-id=<6b4185a0-8e7b-422b-9a8d-ba467747b153@mtasv.net>
Mar  1 15:13:23 ams postfix/submission/smtpd[49495]: discarding EHLO keywords: CHUNKING
Mar  1 15:13:23 ams postfix/qmgr[38680]: 4TmVS308MWz2qDrL: from=<pm_bounces@pm-bounces.nlinvesteert.nl>, size=12505, nrcpt=1 (queue active)
Mar  1 15:13:23 ams amavis[47558]: Net::Server: 2024/03/01-15:13:23 CONNECT TCP Peer: "[127.0.0.1]:59662" Local: "[127.0.0.1]:10024"
Mar  1 15:13:23 ams amavis[47558]: loaded base policy bank
Mar  1 15:13:23 ams amavis[47558]: lookup_ip_acl (inet_acl) arr.obj: key="127.0.0.1" matches "127.0.0.1", result=1
Mar  1 15:13:23 ams amavis[47558]: process_request: fileno sock=10, STDIN=0, STDOUT=1
Mar  1 15:13:23 ams amavis[47558]: get_deadline switch_to_my_time(new request) - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: prolong_timer switch_to_my_time(new request): timer 288, was 0, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: process_request: suggested_protocol="" on a TCP socket
Mar  1 15:13:23 ams amavis[47558]: (47558-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready
Mar  1 15:13:23 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, smtp response sent
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 4: was busy, 8.3 ms, total idle 0.000 s, busy 0.008 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) smtp readline: read 22 bytes, new size: 22
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 5: was idle, 0.4 ms, total idle 0.000 s, busy 0.008 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) SMTP< EHLO ams.SERVERNAME.com\r\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline switch_to_my_time(rx SMTP EHLO) - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer switch_to_my_time(rx SMTP EHLO): timer 288, was 480, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250-[127.0.0.1]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250-VRFY
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250-PIPELINING
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250-SIZE
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250-ENHANCEDSTATUSCODES
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250-8BITMIME
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250-SMTPUTF8
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250-DSN
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250 XFORWARD NAME ADDR PORT PROTO HELO IDENT SOURCE
Mar  1 15:13:23 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, smtp response sent
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 6: was busy, 1.9 ms, total idle 0.000 s, busy 0.010 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) smtp readline: read 289 bytes, new size: 289
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.001 s, busy 0.010 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP< XFORWARD NAME=sc-ord-mta122.mtasv.net ADDR=50.31.156.122 PORT=57679\r\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 288, was 480, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250 2.5.0 Ok XFORWARD
Mar  1 15:13:23 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, smtp response sent
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 6: was busy, 0.9 ms, total idle 0.001 s, busy 0.011 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.011 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP< XFORWARD PROTO=ESMTP HELO=sc-ord-mta122.mtasv.net IDENT=4TmVS308MWz2qDrL SOURCE=REMOTE\r\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 288, was 480, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250 2.5.0 Ok XFORWARD
Mar  1 15:13:23 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, smtp response sent
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 6: was busy, 0.6 ms, total idle 0.001 s, busy 0.012 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.012 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP< MAIL FROM:<pm_bounces@pm-bounces.nlinvesteert.nl> SIZE=12505 BODY=8BITMIME\r\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline switch_to_my_time(rx SMTP MAIL) - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer switch_to_my_time(rx SMTP MAIL): timer 288, was 480, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) check_mail_begin_task: task_count=1
Mar  1 15:13:23 ams amavis[47558]: (47558-01) TempDir::prepare_dir: created directory /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp
Mar  1 15:13:23 ams amavis[47558]: (47558-01) TempDir::prepare_file: creating file /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp/email.txt
Mar  1 15:13:23 ams amavis[47558]: (47558-01) TempDir::prepare_file: layers: unix,perlio
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_ip_acl (client_ipaddr_policy) arr.obj: key="50.31.156.122", no match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [debug_sender] => undef, "pm_bounces@pm-bounces.nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) mesage size set to a declared size 12505
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250 2.1.0 Sender <pm_bounces@pm-bounces.nlinvesteert.nl> OK
Mar  1 15:13:23 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, smtp response sent
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 6: was busy, 4.7 ms, total idle 0.001 s, busy 0.016 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.016 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP< RCPT TO:<info@XXXX.nl> ORCPT=rfc822;info@XXXX.nl\r\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline switch_to_my_time(rx SMTP RCPT) - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer switch_to_my_time(rx SMTP RCPT): timer 288, was 480, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup => undef, "info@XXXX.nl", no lookup tables
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup: (scalar) matches, result="1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [local_domains] => true,  "info@XXXX.nl" matches, result="1", matching_key="(constant:1)"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: info@XXXX.nl, info, @XXXX.nl, @.XXXX.nl, @.nl, @.
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql sel_policy "info@XXXX.nl", query args: [info@XXXX.nl,-3], [info,-3], [@XXXX.nl,-3], [@.XXXX.nl,-3], [@.nl,-3], [@.,-3]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql select: SELECT users.*, policy.*, users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?) ORDER BY users.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin, nontransaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) Connecting to SQL database server
Mar  1 15:13:23 ams amavis[47558]: (47558-01) connect_to_sql: trying 'DBI:mysql:database=amavisd;host=127.0.0.1;port=3306'
Mar  1 15:13:23 ams amavis[47558]: (47558-01) connect_to_sql: 'DBI:mysql:database=amavisd;host=127.0.0.1;port=3306' succeeded
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: preparing and executing (6 args): SELECT users.*, policy.*, users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?) ORDER BY users.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql: "info@XXXX.nl" matches catchall, local=>undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql(info@XXXX.nl) matches, result=(id=>"17", priority=>"10", policy_id=>"17", email=>"info@XXXX.nl", fullname=>-, id=>"17", policy_name=>"info@XXXX.nl", virus_lover=>"N", spam_lover=>"N", unchecked_lover=>-, banned_files_lover=>"N", bad_header_lover=>"N", bypass_virus_checks=>"N", bypass_spam_checks=>"N", bypass_banned_checks=>"N", bypass_header_checks=>"N", virus_quarantine_to=>"virus-quarantine", spam_quarantine_to=>"spam-quarantine", banned_quarantine_to=>"banned-quarantine", unchecked_quarantine_to=>-, bad_header_quarantine_to=>"bad-header-quarantine", clean_quarantine_to=>-, archive_quarantine_to=>-, spam_tag_level=>-, spam_tag2_level=>"0", spam_tag3_level=>"0", spam_kill_level=>-, spam_dsn_cutoff_level=>-, spam_quarantine_cutoff_level=>-, addr_extension_virus=>-, addr_extension_spam=>-, addr_extension_banned=>-, addr_extension_bad_header=>-, warnvirusrecip=>-, warnbannedrecip=>-, warnbadhrecip=>-, newvirus_admin=>-, virus_admin=>-, banned_...
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ...admin=>-, bad_header_admin=>-, spam_admin=>-, spam_subject_tag=>-, spam_subject_tag2=>"[SPAM] ", spam_subject_tag3=>"[SPAM] ", message_size_limit=>-, banned_rulenames=>"", disclaimer_options=>-, forward_method=>-, sa_userconf=>-, sa_username=>-, id=>"17")
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql(info@XXXX.nl) matches, result=(id=>"16", priority=>"5", policy_id=>"16", email=>"@XXXX.nl", fullname=>-, id=>"16", policy_name=>"@XXXX.nl", virus_lover=>"N", spam_lover=>"N", unchecked_lover=>-, banned_files_lover=>"N", bad_header_lover=>"N", bypass_virus_checks=>"N", bypass_spam_checks=>"N", bypass_banned_checks=>"N", bypass_header_checks=>"N", virus_quarantine_to=>"virus-quarantine", spam_quarantine_to=>"spam-quarantine", banned_quarantine_to=>"banned-quarantine", unchecked_quarantine_to=>-, bad_header_quarantine_to=>"bad-header-quarantine", clean_quarantine_to=>-, archive_quarantine_to=>-, spam_tag_level=>-, spam_tag2_level=>"0", spam_tag3_level=>"0", spam_kill_level=>"0", spam_dsn_cutoff_level=>-, spam_quarantine_cutoff_level=>-, addr_extension_virus=>-, addr_extension_spam=>-, addr_extension_banned=>-, addr_extension_bad_header=>-, warnvirusrecip=>-, warnbannedrecip=>-, warnbadhrecip=>-, newvirus_admin=>-, virus_admin=>-, banned_admin=>...
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ...-, bad_header_admin=>-, spam_admin=>-, spam_subject_tag=>-, spam_subject_tag2=>"[SPAM] ", spam_subject_tag3=>"[SPAM] ", message_size_limit=>-, banned_rulenames=>"", disclaimer_options=>-, forward_method=>-, sa_userconf=>-, sa_username=>-, id=>"16")
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql(info@XXXX.nl) matches, result=(id=>"1", priority=>"0", policy_id=>"1", email=>"@.", fullname=>-, id=>"1", policy_name=>"@.", virus_lover=>"N", spam_lover=>"N", unchecked_lover=>-, banned_files_lover=>"N", bad_header_lover=>"N", bypass_virus_checks=>"N", bypass_spam_checks=>"N", bypass_banned_checks=>"N", bypass_header_checks=>"N", virus_quarantine_to=>"virus-quarantine", spam_quarantine_to=>"spam-quarantine", banned_quarantine_to=>"banned-quarantine", unchecked_quarantine_to=>-, bad_header_quarantine_to=>"bad-header-quarantine", clean_quarantine_to=>-, archive_quarantine_to=>-, spam_tag_level=>"0", spam_tag2_level=>"0", spam_tag3_level=>"0", spam_kill_level=>"0", spam_dsn_cutoff_level=>-, spam_quarantine_cutoff_level=>-, addr_extension_virus=>-, addr_extension_spam=>-, addr_extension_banned=>-, addr_extension_bad_header=>-, warnvirusrecip=>-, warnbannedrecip=>-, warnbadhrecip=>-, newvirus_admin=>-, virus_admin=>-, banned_admin=>-, bad_header...
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ..._admin=>-, spam_admin=>-, spam_subject_tag=>-, spam_subject_tag2=>"[SPAM] ", spam_subject_tag3=>"[SPAM] ", message_size_limit=>-, banned_rulenames=>"", disclaimer_options=>-, forward_method=>-, sa_userconf=>-, sa_username=>-, id=>"1", local=>-)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(message_size_limit) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(message_size_limit) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(message_size_limit) rec=2, "info@XXXX.nl" result: undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [message_size_limit] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 250 2.1.5 Recipient <info@XXXX.nl> OK
Mar  1 15:13:23 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, smtp response sent
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 6: was busy, 11.6 ms, total idle 0.001 s, busy 0.028 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.028 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP< DATA\r\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline switch_to_my_time(rx SMTP DATA) - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer switch_to_my_time(rx SMTP DATA): timer 288, was 480, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP [127.0.0.1]:10024 /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp: <pm_bounces@pm-bounces.nlinvesteert.nl> -> <info@XXXX.nl> SIZE=12505 BODY=8BITMIME Received: from ams.SERVERNAME.com ([127.0.0.1]) by ams.SERVERNAME.com (ams.SERVERNAME.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <info@XXXX.nl>; Fri,  1 Mar 2024 15:13:23 +0100 (CET)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP> 354 End data with <CR><LF>.<CR><LF>
Mar  1 15:13:23 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, smtp response sent
Mar  1 15:13:23 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, receiving data
Mar  1 15:13:23 ams postfix/smtpd[49499]: disconnect from sc-ord-mta122.mtasv.net[50.31.156.122] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
Mar  1 15:13:23 ams amavis[47558]: (47558-01) smtp copy: read 12514 bytes into buffer, new size: 12514
Mar  1 15:13:23 ams amavis[47558]: (47558-01) smtp copy: 6 bytes still buffered at end
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline switch_to_my_time(rx data-end) - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer switch_to_my_time(rx data-end): timer 288, was 480, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ESMTP< .<CR><LF>
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline get_body_digest - deadline in 480.0 s, set to 30.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline digest_pre - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer digest_pre: timer 288, was 288, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) DNS resolver created, UDP payload size 1220, NS: 23.19.53.53, 23.19.52.52
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_body_digest: reading header section from memory
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_body_digest: feeding header section to DKIM verifier
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_body_digest: sending h/b separator to DKIM
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline digest_hdr - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer digest_hdr: timer 288, was 288, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_body_digest: reading mail body from memory, 2 DKIM signatures
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline digest_body - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer digest_body: timer 288, was 288, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_body_digest: message size adjusted 12505 -> 12503, header+sep 2320, body 10183
Mar  1 15:13:23 ams amavis[47558]: (47558-01) body type (8bit-MIMEtransport): labeled 8BITMIME unnecessarily (h=0, b=0)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) body hash: d1e92ebcaf0985ebf66b189309d488c8
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ip_from_received: 50.31.156.122
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ip_from_received: no IP address in:  by sc-ord-mta122.mtasv.net id hs7h7o34o8g3 for <info@XXXX.nl>; Fri, 1 Mar 2024 09:13:16 -0500 (envelope-from <pm_bounces@pm-bounces.nlinvesteert.nl>)\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_ip_acl (public_nets) arr.obj: key="127.0.0.1" matches "!127.0.0.0/8", result=0
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_ip_acl (public_nets) arr.obj: key="50.31.156.122" matches "::ffff:0:0/96", result=1
Mar  1 15:13:23 ams amavis[47558]: (47558-01) trace: ESMTP://[127.0.0.1]:59662 < ESMTPS://[50.31.156.122]:57679 < x
Mar  1 15:13:23 ams amavis[47558]: (47558-01) dkim: public key s=pm20231108 d=pm.mtasv.net v=DKIM1 k=rsa, 1024-bit key
Mar  1 15:13:23 ams amavis[47558]: (47558-01) dkim: VALID third-party signature by d=pm.mtasv.net, From: <info@nlinvesteert.nl>, a=rsa-sha1, c=relaxed/relaxed, s=pm20231108, i=@pm.mtasv.net
Mar  1 15:13:23 ams amavis[47558]: (47558-01) dkim: public key s=20211030121309pm d=nlinvesteert.nl k=rsa, 1024-bit key
Mar  1 15:13:23 ams amavis[47558]: (47558-01) dkim: VALID Author+Sender signature by d=nlinvesteert.nl, From: <info@nlinvesteert.nl>, a=rsa-sha256, c=relaxed/relaxed, s=20211030121309pm, i=info@nlinvesteert.nl
Mar  1 15:13:23 ams amavis[47558]: (47558-01) Original mail size: 12503; quota set to: 6251500 bytes (fmin=5, fmax=500, qmin=102400, qmax=524288000)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) generate_mail_id retry: C5o5J4pqhKU+
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin, nontransaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: preparing and executing (2 args): SELECT id FROM maddr WHERE partition_tag=? AND email=?
Mar  1 15:13:23 ams amavis[47558]: (47558-01) save_info_preliminary zlF2hpQDNhMy, sender id: 30333, pm_bounces@pm-bounces.nlinvesteert.nl, exists
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin, nontransaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: executing clause (2 args): SELECT id FROM maddr WHERE partition_tag=? AND email=?
Mar  1 15:13:23 ams amavis[47558]: (47558-01) orcpt_encode rfc822, info@XXXX.nl, smtputf8
Mar  1 15:13:23 ams amavis[47558]: (47558-01) save_info_preliminary zlF2hpQDNhMy, recip id: 77, info@XXXX.nl (ORCPT rfc822;info@XXXX.nl), exists
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin transaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: preparing and executing (11 args): INSERT INTO msgs (partition_tag, mail_id, secret_id, am_id, time_num, time_iso, sid, policy, client_addr, size, host) VALUES (?,?,?,?,?,?,?,?,?,?,?)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql commit
Mar  1 15:13:23 ams amavis[47558]: (47558-01) Checking: zlF2hpQDNhMy [50.31.156.122] <pm_bounces@pm-bounces.nlinvesteert.nl> -> <info@XXXX.nl>
Mar  1 15:13:23 ams amavis[47558]: (47558-01) 2822.From: <info@nlinvesteert.nl>, 2821.Mail_From: <pm_bounces@pm-bounces.nlinvesteert.nl>
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(local) rec=0, "info@XXXX.nl" result: "1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field, no such fields: local
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [local_domains] => true,  "info@XXXX.nl" matches, result="1", matching_key="/cached/"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(bypass_virus_checks) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [bypass_virus_checks] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(bypass_banned_checks) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [bypass_banned_checks] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(bypass_spam_checks) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [bypass_spam_checks] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(id) rec=0, "info@XXXX.nl" result: "17"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(id) rec=1, "info@XXXX.nl" result: "16"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(id) rec=2, "info@XXXX.nl" result: "1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [users.id], 3 matches for "info@XXXX.nl", results: "/cached/"=>"17", "/cached/"=>"16", "/cached/"=>"1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(policy_id) rec=0, "info@XXXX.nl" result: "17"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [users.policy_id] => true,  "info@XXXX.nl" matches, result="17", matching_key="/cached/"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) Extracting mime components from a string
Mar  1 15:13:23 ams amavis[47558]: (47558-01) Issued a new file name: p001
Mar  1 15:13:23 ams amavis[47558]: (47558-01) Charging 9768 bytes to remaining quota 6251500 (out of 6251500, (0%)) - by mime_decode
Mar  1 15:13:23 ams amavis[47558]: (47558-01) p001 1 Content-Type: text/html, QP, size: 9768, SHA1 digest: 33e3ff827424da4f460dd514044213da3fa97d99
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline mime_decode - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer mime_decode: timer 288, was 288, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline mime_decode-1 - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer mime_decode-1: timer 288, was 288, deadline in 480.0 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) decode_parts: level=1, #parts=1 : p001
Mar  1 15:13:23 ams amavis[47558]: (47558-01) using File::LibMagic on 1 files
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_re("HTML document, ASCII text, with very long lines") matches key "(?^i:\\btext\\b)", result="asc"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [map_full_type_to_short_type] => true,  "HTML document, ASCII text, with very long lines" matches, result="asc", matching_key="(?^i:\\btext\\b)"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) File-type of p001: HTML document, ASCII text, with very long lines; (asc)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) decompose_part: p001 - atomic
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline parts_decode - deadline in 479.9 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer parts_decode: timer 288, was 288, deadline in 479.9 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(bypass_header_checks) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [bypass_header_checks] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) check_header: 0, OK
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(bypass_header_checks) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [bypass_header_checks] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) Checking for banned types and filenames
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(banned_rulenames) rec=0, "info@XXXX.nl" result: ""
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(banned_rulenames) rec=1, "info@XXXX.nl" result: ""
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(banned_rulenames) rec=2, "info@XXXX.nl" result: ""
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup: (scalar) matches, result="DEFAULT"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [banned_filename], 4 matches for "info@XXXX.nl", results: "/cached/"=>"", "/cached/"=>"", "/cached/"=>"", "(constant:DEFAULT)"=>"DEFAULT"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) collect banned table[0]: info@XXXX.nl, tables:
Mar  1 15:13:23 ams amavis[47558]: (47558-01) collect banned table[1]: info@XXXX.nl, tables:
Mar  1 15:13:23 ams amavis[47558]: (47558-01) collect banned table[2]: info@XXXX.nl, tables:
Mar  1 15:13:23 ams amavis[47558]: (47558-01) collect banned table[3]: info@XXXX.nl, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x55b495e02d78)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) starting banned checks - traversing message structure tree
Mar  1 15:13:23 ams amavis[47558]: (47558-01) check_for_banned (p001) text/html,.asc
Mar  1 15:13:23 ams amavis[47558]: (47558-01) doing banned check for info@XXXX.nl on text/html,.asc
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_re(["text/html",".asc"]), no matches
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [check_bann:info@XXXX.nl] => undef, ["text/html",".asc"] does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_re("P=p001\tL=1\tM=text/html\tT=asc"), no matches
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [banned_namepath_re] => undef, "P=p001\tL=1\tM=text/html\tT=asc" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) p.path info@XXXX.nl: "P=p001,L=1,M=text/html,T=asc"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) banned check: any=0, all=N (1)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_re("MAIL"), no matches
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [keep_decoded_original] => undef, "MAIL" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) Calling virus scanners, 1 files to scan in /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp/parts
Mar  1 15:13:23 ams amavis[47558]: (47558-01) invoking av-scanner clamav-socket
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ask_daemon: proto=DFLT, spawn=0, (clamav-socket) /var/run/clamd.amavisd/clamd.socket
Mar  1 15:13:23 ams amavis[47558]: (47558-01) run_av (clamav-socket): query template(1,0): CONTSCAN {}\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline run_av_pre - deadline in 479.9 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer run_av_pre: timer 288, was 288, deadline in 479.9 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline run_av_scan - deadline in 479.9 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer run_av_scan: timer 288, was 288, deadline in 479.9 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) run_av Using (clamav-socket): (code) CONTSCAN /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp/parts\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline ask_daemon_internal_connect_pre - deadline in 479.9 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline ask_daemon_internal_connect - deadline in 479.9 s, set to 10.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer ask_daemon_internal_connect: timer 10, was 288, deadline in 479.9 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) clamav-socket: Connecting to socket  /var/run/clamd.amavisd/clamd.socket
Mar  1 15:13:23 ams amavis[47558]: (47558-01) new socket by IO::Socket::UNIX to /var/run/clamd.amavisd/clamd.socket, timeout set to 10
Mar  1 15:13:23 ams amavis[47558]: (47558-01) connected to /var/run/clamd.amavisd/clamd.socket successfully
Mar  1 15:13:23 ams amavis[47558]: (47558-01) clamav-socket: Sending CONTSCAN /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp/parts\n to socket /var/run/clamd.amavisd/clamd.socket
Mar  1 15:13:23 ams amavis[47558]: (47558-01) rw_loop: needline=0, flush=1, wr=1, timeout=10
Mar  1 15:13:23 ams clamd[122791]: SelfCheck: Database status OK.
Mar  1 15:13:23 ams amavis[47558]: (47558-01) rw_loop: sending 76 chars
Mar  1 15:13:23 ams amavis[47558]: (47558-01) rw_loop sent 76> CONTSCAN /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp/parts\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline ask_daemon_internal_scan - deadline in 479.9 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer ask_daemon_internal_scan: timer 288, was 10, deadline in 479.9 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) rw_loop: needline=0, flush=0, wr=0, timeout=287.999
Mar  1 15:13:23 ams amavis[47558]: (47558-01) rw_loop: receiving
Mar  1 15:13:23 ams amavis[47558]: (47558-01) rw_loop read 71 chars< /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp/parts: OK\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) rw_loop: needline=0, flush=0, wr=0, timeout=287.999
Mar  1 15:13:23 ams amavis[47558]: (47558-01) rw_loop: receiving
Mar  1 15:13:23 ams amavis[47558]: (47558-01) rw_loop read: got eof

3 Reply by leonnl

  • leonnl
  • Member
  • Offline
  • Registered: 2024-03-01
  • Posts: 4

Re: A lot of clean email with low spam scores is quarantined

Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline ask_daemon_internal - deadline in 479.9 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer ask_daemon_internal: timer 288, was 288, deadline in 479.9 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline run_av_3 - deadline in 479.9 s, set to 288.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer run_av_3: timer 288, was 288, deadline in 479.9 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) run_av (clamav-socket) result: /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp/parts: OK\n
Mar  1 15:13:23 ams amavis[47558]: (47558-01) run_av (clamav-socket): CLEAN
Mar  1 15:13:23 ams amavis[47558]: (47558-01) run_av (clamav-socket) result: clean
Mar  1 15:13:23 ams amavis[47558]: (47558-01) wbl: checking sender <pm_bounces@pm-bounces.nlinvesteert.nl>, <info@nlinvesteert.nl>
Mar  1 15:13:23 ams amavis[47558]: (47558-01) wbl: (SQL) recip <info@XXXX.nl>, 3 matches
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup: (scalar) matches, result="1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [local_domains] => true,  "pm_bounces@pm-bounces.nlinvesteert.nl" matches, result="1", matching_key="(constant:1)"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: pm_bounces@pm-bounces.nlinvesteert.nl, pm_bounces, @pm-bounces.nlinvesteert.nl, @.pm-bounces.nlinvesteert.nl, @.nlinvesteert.nl, @.nl, @.
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql sel_wblist "pm_bounces@pm-bounces.nlinvesteert.nl", query args: "17", [pm_bounces@pm-bounces.nlinvesteert.nl,-3], [pm_bounces,-3], [@pm-bounces.nlinvesteert.nl,-3], [@.pm-bounces.nlinvesteert.nl,-3], [@.nlinvesteert.nl,-3], [@.nl,-3], [@.,-3]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql select: SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin, nontransaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: preparing and executing (8 args): SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql, "pm_bounces@pm-bounces.nlinvesteert.nl" no match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(wb), "pm_bounces@pm-bounces.nlinvesteert.nl" no matching records
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup => undef, "pm_bounces@pm-bounces.nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) wbl: (SQL) recip <info@XXXX.nl>, rid=17, got: ""
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup: (scalar) matches, result="1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [local_domains] => true,  "pm_bounces@pm-bounces.nlinvesteert.nl" matches, result="1", matching_key="(constant:1)"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: cached pm_bounces@pm-bounces.nlinvesteert.nl
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql sel_wblist "pm_bounces@pm-bounces.nlinvesteert.nl", query args: "16", [pm_bounces@pm-bounces.nlinvesteert.nl,-3], [pm_bounces,-3], [@pm-bounces.nlinvesteert.nl,-3], [@.pm-bounces.nlinvesteert.nl,-3], [@.nlinvesteert.nl,-3], [@.nl,-3], [@.,-3]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql select: SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin, nontransaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: executing clause (8 args): SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql, "pm_bounces@pm-bounces.nlinvesteert.nl" no match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(wb), "pm_bounces@pm-bounces.nlinvesteert.nl" no matching records
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup => undef, "pm_bounces@pm-bounces.nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) wbl: (SQL) recip <info@XXXX.nl>, rid=16, got: ""
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup: (scalar) matches, result="1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [local_domains] => true,  "pm_bounces@pm-bounces.nlinvesteert.nl" matches, result="1", matching_key="(constant:1)"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: cached pm_bounces@pm-bounces.nlinvesteert.nl
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql sel_wblist "pm_bounces@pm-bounces.nlinvesteert.nl", query args: "1", [pm_bounces@pm-bounces.nlinvesteert.nl,-3], [pm_bounces,-3], [@pm-bounces.nlinvesteert.nl,-3], [@.pm-bounces.nlinvesteert.nl,-3], [@.nlinvesteert.nl,-3], [@.nl,-3], [@.,-3]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql select: SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin, nontransaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: executing clause (8 args): SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql, "pm_bounces@pm-bounces.nlinvesteert.nl" no match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(wb), "pm_bounces@pm-bounces.nlinvesteert.nl" no matching records
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup => undef, "pm_bounces@pm-bounces.nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) wbl: (SQL) recip <info@XXXX.nl>, rid=1, got: ""
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [blacklist_recip<info@XXXX.nl>] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [blacklist_sender<pm_bounces@pm-bounces.nlinvesteert.nl>,blacklist_sender] => undef, "pm_bounces@pm-bounces.nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [whitelist_recip<info@XXXX.nl>] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [whitelist_sender<pm_bounces@pm-bounces.nlinvesteert.nl>,whitelist_sender] => undef, "pm_bounces@pm-bounces.nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: info@XXXX.nl, info@, XXXX.nl, .XXXX.nl, .nl, .
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_hash(info@XXXX.nl) matches keys: "."=>ARRAY(0x55b495ec5270)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [score_recip<info@XXXX.nl>,score_sender], 1 matches for "info@XXXX.nl", results: "."=>[Amavis::Lookup::RE=ARRAY(0x55b495eb5508),{ntbugtraq@listserv.ntbugtraq.com=>"-3",securityfocus.com=>"-3",cert-advisory@us-cert.gov=>"-3",amavis-user-bounces@lists.sourceforge.net=>"-3",owner-technews@postel.acm.org=>"-3",owner-textbreakingnews@cnnimail12.cnn.com=>"-5",.example.net=>"1",returns.groups.yahoo.com=>"-3",notification-return@lists.sophos.com=>"-3",spamassassin.apache.org=>"-3",clusternews@linuxnetworx.com=>"-3",ietf-123-owner@loki.ietf.org=>"-3",mailman-announce-admin@python.org=>"-3",security-alerts@linuxsecurity.com=>"-3",rt-users-admin@lists.fsck.com=>"-3",surveys-errors@lists.nua.ie=>"-3",owner-sendmail-announce@lists.sendmail.org=>"-3",sendmail-announce-request@lists.sendmail.org=>"-3",nobody@cert.org=>"-3",owner-postfix-users@postfix.org=>"-3",ca+envelope@sendmail.org=>"-3",yahoo-dev-null@yahoo-inc.com=>"-3",noreply@freshmeat.net=>"-3",clp-req...
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ...uest@comp.nus.edu.sg=>"-3",donotreply@sendmail.org=>"-3",slashdot@slashdot.org=>"-3",emailnews@genomeweb.com=>"-5",owner-postfix-announce@postfix.org=>"-3",cvs-commits-list-admin@gnome.org=>"-3",owner-alert@iss.net=>"-3",sender@example.net=>"3",amavis-user-admin@lists.sourceforge.net=>"-3",lvs-users-admin@linuxvirtualserver.org=>"-3"}]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_re("pm_bounces@pm-bounces.nlinvesteert.nl"), no matches
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: pm_bounces@pm-bounces.nlinvesteert.nl, pm_bounces@, pm-bounces.nlinvesteert.nl, .pm-bounces.nlinvesteert.nl, .nlinvesteert.nl, .nl, .
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_hash(pm_bounces@pm-bounces.nlinvesteert.nl), no matches
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [score_sender<pm_bounces@pm-bounces.nlinvesteert.nl>] => undef, "pm_bounces@pm-bounces.nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup: (scalar) matches, result="1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [local_domains] => true,  "info@nlinvesteert.nl" matches, result="1", matching_key="(constant:1)"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: info@nlinvesteert.nl, info, @nlinvesteert.nl, @.nlinvesteert.nl, @.nl, @.
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql sel_wblist "info@nlinvesteert.nl", query args: "17", [info@nlinvesteert.nl,-3], [info,-3], [@nlinvesteert.nl,-3], [@.nlinvesteert.nl,-3], [@.nl,-3], [@.,-3]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql select: SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin, nontransaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: preparing and executing (7 args): SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql, "info@nlinvesteert.nl" no match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(wb), "info@nlinvesteert.nl" no matching records
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup => undef, "info@nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) wbl: (SQL) recip <info@XXXX.nl>, rid=17, got: ""
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup: (scalar) matches, result="1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [local_domains] => true,  "info@nlinvesteert.nl" matches, result="1", matching_key="(constant:1)"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: cached info@nlinvesteert.nl
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql sel_wblist "info@nlinvesteert.nl", query args: "16", [info@nlinvesteert.nl,-3], [info,-3], [@nlinvesteert.nl,-3], [@.nlinvesteert.nl,-3], [@.nl,-3], [@.,-3]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql select: SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin, nontransaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: executing clause (7 args): SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql, "info@nlinvesteert.nl" no match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(wb), "info@nlinvesteert.nl" no matching records
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup => undef, "info@nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) wbl: (SQL) recip <info@XXXX.nl>, rid=16, got: ""
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup: (scalar) matches, result="1"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [local_domains] => true,  "info@nlinvesteert.nl" matches, result="1", matching_key="(constant:1)"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: cached info@nlinvesteert.nl
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql sel_wblist "info@nlinvesteert.nl", query args: "1", [info@nlinvesteert.nl,-3], [info,-3], [@nlinvesteert.nl,-3], [@.nlinvesteert.nl,-3], [@.nl,-3], [@.,-3]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql select: SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql begin, nontransaction
Mar  1 15:13:23 ams amavis[47558]: (47558-01) sql: executing clause (7 args): SELECT wb FROM wblist JOIN mailaddr ON wblist.sid=mailaddr.id WHERE wblist.rid=? AND mailaddr.email IN (?,?,?,?,?,?) ORDER BY mailaddr.priority DESC
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql, "info@nlinvesteert.nl" no match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(wb), "info@nlinvesteert.nl" no matching records
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup => undef, "info@nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) wbl: (SQL) recip <info@XXXX.nl>, rid=1, got: ""
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [blacklist_recip<info@XXXX.nl>] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [blacklist_sender<info@nlinvesteert.nl>,blacklist_sender] => undef, "info@nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [whitelist_recip<info@XXXX.nl>] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [whitelist_sender<info@nlinvesteert.nl>,whitelist_sender] => undef, "info@nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: cached info@XXXX.nl
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_hash(info@XXXX.nl) matches keys: "."=>ARRAY(0x55b495ec5270)
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [score_recip<info@XXXX.nl>,score_sender], 1 matches for "info@XXXX.nl", results: "."=>[Amavis::Lookup::RE=ARRAY(0x55b495eb5508),{ntbugtraq@listserv.ntbugtraq.com=>"-3",securityfocus.com=>"-3",cert-advisory@us-cert.gov=>"-3",amavis-user-bounces@lists.sourceforge.net=>"-3",owner-technews@postel.acm.org=>"-3",owner-textbreakingnews@cnnimail12.cnn.com=>"-5",.example.net=>"1",returns.groups.yahoo.com=>"-3",notification-return@lists.sophos.com=>"-3",spamassassin.apache.org=>"-3",clusternews@linuxnetworx.com=>"-3",ietf-123-owner@loki.ietf.org=>"-3",mailman-announce-admin@python.org=>"-3",security-alerts@linuxsecurity.com=>"-3",rt-users-admin@lists.fsck.com=>"-3",surveys-errors@lists.nua.ie=>"-3",owner-sendmail-announce@lists.sendmail.org=>"-3",sendmail-announce-request@lists.sendmail.org=>"-3",nobody@cert.org=>"-3",owner-postfix-users@postfix.org=>"-3",ca+envelope@sendmail.org=>"-3",yahoo-dev-null@yahoo-inc.com=>"-3",noreply@freshmeat.net=>"-3",clp-req...
Mar  1 15:13:23 ams amavis[47558]: (47558-01) ...uest@comp.nus.edu.sg=>"-3",donotreply@sendmail.org=>"-3",slashdot@slashdot.org=>"-3",emailnews@genomeweb.com=>"-5",owner-postfix-announce@postfix.org=>"-3",cvs-commits-list-admin@gnome.org=>"-3",owner-alert@iss.net=>"-3",sender@example.net=>"3",amavis-user-admin@lists.sourceforge.net=>"-3",lvs-users-admin@linuxvirtualserver.org=>"-3"}]
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_re("info@nlinvesteert.nl"), no matches
Mar  1 15:13:23 ams amavis[47558]: (47558-01) query_keys: info@nlinvesteert.nl, info@, nlinvesteert.nl, .nlinvesteert.nl, .nl, .
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_hash(info@nlinvesteert.nl), no matches
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [score_sender<info@nlinvesteert.nl>] => undef, "info@nlinvesteert.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) SpamControl: calling spam scanner SpamAssassin
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline spam_scan_sa_pre - deadline in 479.9 s, set to 476.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) prolong_timer spam_scan_sa_pre: timer 476, was 288, deadline in 479.9 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(sa_userconf) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(sa_userconf) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(sa_userconf) rec=2, "info@XXXX.nl" result: undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [sa_userconf] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(sa_username) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(sa_username) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup_sql_field(sa_username) rec=2, "info@XXXX.nl" result: undef
Mar  1 15:13:23 ams amavis[47558]: (47558-01) lookup [sa_username] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:23 ams amavis[47558]: (47558-01) SA user config: "", username: "amavis", 0, (0)info@XXXX.nl
Mar  1 15:13:23 ams amavis[47558]: (47558-01) calling SA parse (0), SA vers 3.4.6, 3.004006, data as STRING_REF, recips_ind [0], user: "amavis"
Mar  1 15:13:23 ams amavis[47558]: (47558-01) get_deadline SA check - deadline in 479.9 s, set to 475.000 s
Mar  1 15:13:23 ams amavis[47558]: (47558-01) mimepart digest: 33e3ff827424da4f460dd514044213da3fa97d99:text/html
Mar  1 15:13:23 ams amavis[47558]: (47558-01) CALLING SA check (0)
Mar  1 15:13:24 ams amavis[47558]: (47558-01) DONE SA check (0)
Mar  1 15:13:24 ams amavis[47558]: (47558-01) get_deadline spam_scan_sa - deadline in 479.2 s, set to 288.000 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) prolong_timer spam_scan_sa: timer 288, was 476, deadline in 479.2 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) spam_scan: score=0.43 autolearn=no autolearn_force=no tests=[DKIMWL_WL_HIGH=-0.096,DKIM_SIGNED=0.1,DKIM_VALID=-0.1,DKIM_VALID_AU=-0.1,DKIM_VALID_EF=-0.1,HTML_MESSAGE=0.001,HTML_MIME_NO_HTML_TAG=0.635,LOTS_OF_MONEY=0.001,MIME_HTML_ONLY=0.1,RCVD_IN_MSPIKE_H2=-0.001,SPF_HELO_PASS=-0.001,SPF_PASS=-0.001,T_SCC_BODY_TEXT_LINE=-0.01,URIBL_BLOCKED=0.001,URI_TRUNCATED=0.001] recips=0
Mar  1 15:13:24 ams amavis[47558]: (47558-01) get_deadline spam_scan - deadline in 479.2 s, set to 288.000 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) prolong_timer spam_scan: timer 288, was 288, deadline in 479.2 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup => undef, "@pm.mtasv.net", no lookup tables
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup => undef, "@nlinvesteert.nl", no lookup tables
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag_level) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag_level) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag_level) rec=2, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_tag_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag2_level) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_tag2_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag3_level) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_tag3_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_kill_level) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_kill_level) rec=1, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_kill_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(message_size_limit) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(message_size_limit) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(message_size_limit) rec=2, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [message_size_limit] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_lover) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [Lovers2,spam_lovers] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) blocking contents category is (6) for info@XXXX.nl, final_destiny 0
Mar  1 15:13:24 ams amavis[47558]: (47558-01) final_destiny 0, recip info@XXXX.nl
Mar  1 15:13:24 ams amavis[47558]: (47558-01) blocking ccat=6, SMTP response: 250 2.7.0 Ok, discarded, id=47558-01 - spam
Mar  1 15:13:24 ams amavis[47558]: (47558-01) do_notify_and_quar: ccat=Spam (6,0) ("6":Spam, "5,1":Spammy3, "5":Spammy, "1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(6), qar_mth=
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_quarantine_to) rec=0, "info@XXXX.nl" result: "spam-quarantine"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_quarantine_to] => true,  "info@XXXX.nl" matches, result="spam-quarantine", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_quarantine_cutoff_level) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_quarantine_cutoff_level) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_quarantine_cutoff_level) rec=2, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_quarantine_cutoff_level] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_admin) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_admin) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_admin) rec=2, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_admin] => undef, "info@XXXX.nl" does not match
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_quarantine_bysender_to] => undef, "pm_bounces@pm-bounces.nlinvesteert.nl" does not match
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag_level) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag_level) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag_level) rec=2, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_tag_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag2_level) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_tag2_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_kill_level) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_kill_level) rec=1, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_kill_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header_edits_for_quar: <pm_bounces@pm-bounces.nlinvesteert.nl> -> <info@XXXX.nl>, Yes, score=0.43 tag=0 tag2=0 kill=0 tests=[DKIMWL_WL_HIGH=-0.096, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, HTML_MESSAGE=0.001, HTML_MIME_NO_HTML_TAG=0.635, LOTS_OF_MONEY=0.001, MIME_HTML_ONLY=0.1, RCVD_IN_MSPIKE_H2=-0.001, SPF_HELO_PASS=-0.001, SPF_PASS=-0.001, T_SCC_BODY_TEXT_LINE=-0.01, URIBL_BLOCKED=0.001, URI_TRUNCATED=0.001] autolearn=no autolearn_force=no
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): X-Spam-Flag: YES
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: X-Spam-Flag: YES\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): X-Spam-Score: 0.43
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: X-Spam-Score: 0.43\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): X-Spam-Level:
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: X-Spam-Level:\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): X-Spam-Status: Yes,\n score=0.43\n tag=0\n tag2=0\n kill=0\n tests=[DKIMWL_WL_HIGH=-0.096,\n DKIM_SIGNED=0.1,\n DKIM_VALID=-0.1,\n DKIM_VALID_AU=-0.1,\n DKIM_VALID_EF=-0.1,\n HTML_MESSAGE=0.001,\n HTML_MIME_NO_HTML_TAG=0.635,\n LOTS_OF_MONEY=0.001,\n MIME_HTML_ONLY=0.1,\n RCVD_IN_MSPIKE_H2=-0.001,\n SPF_HELO_PASS=-0.001,\n SPF_PASS=-0.001,\n T_SCC_BODY_TEXT_LINE=-0.01,\n URIBL_BLOCKED=0.001,\n URI_TRUNCATED=0.001]\n autolearn=no autolearn_force=no
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: X-Spam-Status: Yes, score=0.43 tag=0 tag2=0 kill=0\n\ttests=[DKIMWL_WL_HIGH=-0.096, DKIM_SIGNED=0.1, DKIM_VALID=-0.1,\n\tDKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, HTML_MESSAGE=0.001,\n\tHTML_MIME_NO_HTML_TAG=0.635, LOTS_OF_MONEY=0.001, MIME_HTML_ONLY=0.1,\n\tRCVD_IN_MSPIKE_H2=-0.001, SPF_HELO_PASS=-0.001, SPF_PASS=-0.001,\n\tT_SCC_BODY_TEXT_LINE=-0.01, URIBL_BLOCKED=0.001, URI_TRUNCATED=0.001]\n\tautolearn=no autolearn_force=no\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) quar: scanner provided a header field X-Spam-Checker-Version, inhibited by %allowed_added_header_fields
Mar  1 15:13:24 ams amavis[47558]: (47558-01) quar: scanner provided a header field X-Spam-Flag, but we preferred our own
Mar  1 15:13:24 ams amavis[47558]: (47558-01) quar: scanner provided a header field X-Spam-Level, but we preferred our own
Mar  1 15:13:24 ams amavis[47558]: (47558-01) quar: scanner provided a header field X-Spam-Status, but we preferred our own
Mar  1 15:13:24 ams amavis[47558]: (47558-01) quar: scanner provided a header field X-Spam-Report, inhibited by %allowed_added_header_fields
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): Authentication-Results: ams.SERVERNAME.com (amavisd-new);\n dkim=pass (1024-bit key)\n header.d=pm.mtasv.net\n header.b="Ljwm9aQJ";\n dkim=pass (1024-bit key)\n header.d=nlinvesteert.nl\n header.b="lHT6bKIF"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: Authentication-Results: ams.SERVERNAME.com (amavisd-new);\n\tdkim=pass (1024-bit key) header.d=pm.mtasv.net header.b="Ljwm9aQJ";\n\tdkim=pass (1024-bit key) header.d=nlinvesteert.nl header.b="lHT6bKIF"\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) do_notify_and_quarantine: quarantine spam-quarantine
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): X-Quarantine-ID: <zlF2hpQDNhMy>
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: X-Quarantine-ID: <zlF2hpQDNhMy>\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): X-Envelope-To-Blocked: <info@XXXX.nl>
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: X-Envelope-To-Blocked: <info@XXXX.nl>\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): X-Envelope-To: <info@XXXX.nl>
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: X-Envelope-To: <info@XXXX.nl>\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): X-Envelope-From: <pm_bounces@pm-bounces.nlinvesteert.nl>
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: X-Envelope-From: <pm_bounces@pm-bounces.nlinvesteert.nl>\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header encoded (all-ASCII): Received: from ams.SERVERNAME.com ([127.0.0.1])\n by ams.SERVERNAME.com (ams.SERVERNAME.com [127.0.0.1]) (amavisd-new, port 10024)\n with ESMTP\n id zlF2hpQDNhMy\n for <info@XXXX.nl>;\n Fri,  1 Mar 2024 15:13:23 +0100 (CET)
Mar  1 15:13:24 ams amavis[47558]: (47558-01) header: Received: from ams.SERVERNAME.com ([127.0.0.1])\n\tby ams.SERVERNAME.com (ams.SERVERNAME.com [127.0.0.1]) (amavisd-new, port 10024)\n\twith ESMTP id zlF2hpQDNhMy for <info@XXXX.nl>;\n\tFri,  1 Mar 2024 15:13:23 +0100 (CET)\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) DO_QUARANTINE, sql:, <pm_bounces@pm-bounces.nlinvesteert.nl> -> <info@XXXX.nl>
Mar  1 15:13:24 ams amavis[47558]: (47558-01) delivering to sql:, SEND via SQL (DBI:mysql:database=amavisd;host=127.0.0.1;port=3306): <pm_bounces@pm-bounces.nlinvesteert.nl> -> <info@XXXX.nl>, mail_id zlF2hpQDNhMy
Mar  1 15:13:24 ams amavis[47558]: (47558-01) sql begin transaction
Mar  1 15:13:24 ams amavis[47558]: (47558-01) Amavis::IO::SQL::open w drv=mysql (INSERT INTO quarantine (partition_tag, mail_id, chunk_ind, mail_text) VALUES (?,?,?,?)); key=zlF2hpQDNhMy, p_tag=0
Mar  1 15:13:24 ams amavis[47558]: (47558-01) write_header: 1, Amavis::IO::SQL=HASH(0x55b49cc69570)
Mar  1 15:13:24 ams amavis[47558]: (47558-01) sql flush: key: (zlF2hpQDNhMy, 1), p_tag=0, rx_t=1709302403, size=13349
Mar  1 15:13:24 ams amavis[47558]: (47558-01) sql: preparing and executing (4 args): INSERT INTO quarantine (partition_tag, mail_id, chunk_ind, mail_text) VALUES (?,?,?,?)
Mar  1 15:13:24 ams amavis[47558]: (47558-01) sql commit
Mar  1 15:13:24 ams amavis[47558]: (47558-01) one_response_for_all, per_recip_capable: N, suppressed: N
Mar  1 15:13:24 ams amavis[47558]: (47558-01) one_response_for_all <pm_bounces@pm-bounces.nlinvesteert.nl>: success, r=0,b=0,d=0, ndn_needed=0, '250 2.6.0 Ok, Stored to sql db as mail_id zlF2hpQDNhMy, id=47558-01'
Mar  1 15:13:24 ams amavis[47558]: (47558-01) quar_types: Q, quar_to: zlF2hpQDNhMy
Mar  1 15:13:24 ams amavis[47558]: (47558-01) DO_QUARANTINE done
Mar  1 15:13:24 ams amavis[47558]: (47558-01) skip admin notification, no administrators
Mar  1 15:13:24 ams amavis[47558]: (47558-01) do_notify_and_quarantine - done
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(forward_method) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(forward_method) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(forward_method) rec=2, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup: (opaque) matches, result="smtp:[127.0.0.1]:10025"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [forward_method] => true,  "info@XXXX.nl" matches, result="smtp:[127.0.0.1]:10025", matching_key="(opaque:smtp:[127.0.0.1]:10025)"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) delivery method is 1, recips: info@XXXX.nl
Mar  1 15:13:24 ams amavis[47558]: (47558-01) get_deadline quar+notif - deadline in 479.1 s, set to 288.000 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) prolong_timer quar+notif: timer 288, was 288, deadline in 479.1 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) DSN: sender NOT credible, SA: 0.430, <pm_bounces@pm-bounces.nlinvesteert.nl>
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup: (scalar) matches, result="10"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_dsn_cutoff_level_bysender] => true,  "pm_bounces@pm-bounces.nlinvesteert.nl" matches, result="10", matching_key="(constant:10)"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) dsn: . 250 Spam <pm_bounces@pm-bounces.nlinvesteert.nl> -> <info@XXXX.nl>: on_succ=0, on_dly=1, on_fail=1, never=0, warn_sender=, DSN_passed_on=, destiny=0, mta_resp: "250 2.7.0 Ok, discarded, id=47558-01 - spam"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) DSN: SUCC (discarded) . 250 Spam, destiny=DISCARD: <pm_bounces@pm-bounces.nlinvesteert.nl> -> <info@XXXX.nl>
Mar  1 15:13:24 ams amavis[47558]: (47558-01) delivery_status_notification: notif 0 bytes, suppressed: no
Mar  1 15:13:24 ams amavis[47558]: (47558-01) one_response_for_all, per_recip_capable: N, suppressed: N
Mar  1 15:13:24 ams amavis[47558]: (47558-01) one_response_for_all <pm_bounces@pm-bounces.nlinvesteert.nl>: all DISCARD, '250 2.7.0 Ok, discarded, id=47558-01 - spam'
Mar  1 15:13:24 ams amavis[47558]: (47558-01) notif=N, suppressed=0, ndn_needed=, exit=99, 250 2.7.0 Ok, discarded, id=47558-01 - spam
Mar  1 15:13:24 ams amavis[47558]: (47558-01) get_deadline delivery-notification - deadline in 479.1 s, set to 288.000 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) prolong_timer delivery-notification: timer 288, was 288, deadline in 479.1 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) status counters: InMsgsStatus{Discarded,DiscardedInbound}
Mar  1 15:13:24 ams amavis[47558]: (47558-01) get_deadline snmp-counters - deadline in 479.1 s, set to 288.000 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) prolong_timer snmp-counters: timer 288, was 288, deadline in 479.1 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) orcpt_encode rfc822, info@XXXX.nl, smtputf8
Mar  1 15:13:24 ams amavis[47558]: (47558-01) oldest_public_ip_addr_from_received: 50.31.156.122
Mar  1 15:13:24 ams amavis[47558]: (47558-01) Blocked SPAM {DiscardedInbound,Quarantined}, [50.31.156.122]:57679 [50.31.156.122] ESMTP/ESMTP <pm_bounces@pm-bounces.nlinvesteert.nl> -> <info@XXXX.nl>, (ESMTPS://[50.31.156.122]:57679), quarantine: zlF2hpQDNhMy, Queue-ID: 4TmVS308MWz2qDrL, Message-ID: <6b4185a0-8e7b-422b-9a8d-ba467747b153@mtasv.net>, mail_id: zlF2hpQDNhMy, b: 0ekuvK8Jh, Hits: 0.43, size: 12503, Subject: "Ingangsdatum project Zorghotel en Retraitehuis Zenderen B.V.", From: <info@nlinvesteert.nl> (dkim:AUTHOR), helo=sc-ord-mta122.mtasv.net, Tests: [DKIMWL_WL_HIGH=-0.096,DKIM_SIGNED=0.1,DKIM_VALID=-0.1,DKIM_VALID_AU=-0.1,DKIM_VALID_EF=-0.1,HTML_MESSAGE=0.001,HTML_MIME_NO_HTML_TAG=0.635,LOTS_OF_MONEY=0.001,MIME_HTML_ONLY=0.1,RCVD_IN_MSPIKE_H2=-0.001,SPF_HELO_PASS=-0.001,SPF_PASS=-0.001,T_SCC_BODY_TEXT_LINE=-0.01,URIBL_BLOCKED=0.001,URI_TRUNCATED=0.001], autolearn=no autolearn_force=no, autolearnscore=0.431, dkim_i=@pm.mtasv.net,info@nlinvesteert.nl, dkim_sd=pm20231108:pm.mtasv.net,202110...
Mar  1 15:13:24 ams amavis[47558]: (47558-01) ...30121309pm:nlinvesteert.nl, 927 ms
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag_level) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag_level) rec=1, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag_level) rec=2, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_tag_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_tag2_level) rec=0, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_tag2_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_kill_level) rec=0, "info@XXXX.nl" result: undef
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup_sql_field(spam_kill_level) rec=1, "info@XXXX.nl" result: "0"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) lookup [spam_kill_level] => false, "info@XXXX.nl" matches, result="0", matching_key="/cached/"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) Blocked SPAM, <pm_bounces@pm-bounces.nlinvesteert.nl> -> , Hits: 0.43, tag=0, tag2=0, kill=0, L/Y/Y/Y
Mar  1 15:13:24 ams amavis[47558]: (47558-01) get_deadline main_log_entry - deadline in 479.1 s, set to 288.000 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) prolong_timer main_log_entry: timer 288, was 288, deadline in 479.1 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) sql begin transaction
Mar  1 15:13:24 ams amavis[47558]: (47558-01) sql: preparing and executing (12 args): INSERT INTO msgrcpt (partition_tag, mail_id, rseqnum, rid, is_local, content, ds, rs, bl, wl, bspam_level, smtp_resp) VALUES (?,?,?,?,?,?,?,?,?,?,?,?)
Mar  1 15:13:24 ams amavis[47558]: (47558-01) save_info_final zlF2hpQDNhMy, orig=N, chks=VSHBD, cont.ty=S, q.type=Q, q.to=zlF2hpQDNhMy, dsn=N, score=0.43, Message-ID: <6b4185a0-8e7b-422b-9a8d-ba467747b153@mtasv.net>, From: 'NLInvesteert <info@nlinvesteert.nl>', Subject: 'Ingangsdatum project Zorghotel en Retraitehuis Zenderen B.V.'
Mar  1 15:13:24 ams amavis[47558]: (47558-01) sql: preparing and executing (12 args): UPDATE msgs SET content=?, quar_type=?, quar_loc=?, dsn_sent=?, spam_level=?, message_id=?, from_addr=?, subject=?, client_addr=?, originating=? WHERE partition_tag=? AND mail_id=?
Mar  1 15:13:24 ams amavis[47558]: (47558-01) sql commit
Mar  1 15:13:24 ams amavis[47558]: (47558-01) TIMING-SA total 758 ms - parse: 2.8 (0.4%), extract_message_metadata: 23 (3.1%), get_uri_detail_list: 2.9 (0.4%), tests_pri_-2000: 25 (3.3%), tests_pri_-1000: 2.3 (0.3%), tests_pri_-950: 1.26 (0.2%), tests_pri_-900: 1.33 (0.2%), tests_pri_-90: 1.18 (0.2%), tests_pri_0: 199 (26.3%), check_spf: 25 (3.3%), poll_dns_idle: 0.38 (0.0%), tests_pri_20: 469 (61.9%), check_razor2: 467 (61.7%), tests_pri_30: 1.63 (0.2%), check_pyzor: 0.17 (0.0%), tests_pri_500: 7 (1.0%), get_report: 0.97 (0.1%)
Mar  1 15:13:24 ams amavis[47558]: (47558-01) get_deadline check done - deadline in 479.1 s, set to 288.000 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) prolong_timer check done: timer 288, was 288, deadline in 479.1 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) sending SMTP response: "250 2.7.0 Ok, discarded, id=47558-01 - spam"
Mar  1 15:13:24 ams amavis[47558]: (47558-01) ESMTP> 250 2.7.0 Ok, discarded, id=47558-01 - spam
Mar  1 15:13:24 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, smtp response sent
Mar  1 15:13:24 ams amavis[47558]: (47558-01) TempDir::strip: /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp
Mar  1 15:13:24 ams postfix/amavis/smtp[49512]: 4TmVS308MWz2qDrL: to=<info@XXXX.nl>, relay=127.0.0.1[127.0.0.1]:10024, delay=1.5, delays=0.48/0.04/0.01/0.92, dsn=2.7.0, status=sent (250 2.7.0 Ok, discarded, id=47558-01 - spam)
Mar  1 15:13:24 ams amavis[47558]: (47558-01) rmdir_recursively: /var/spool/amavisd/tmp/amavis-20240301T151323-47558-yrYcQvgp/parts, excl=1
Mar  1 15:13:24 ams postfix/qmgr[38680]: 4TmVS308MWz2qDrL: removed
Mar  1 15:13:24 ams amavis[47558]: (47558-01) size: 12503, TIMING [total 934 ms] - sql-prepare: 4.4 (0%)0, SMTP greeting: 3.9 (0%)1, SMTP EHLO: 2.3 (0%)1, SMTP pre-MAIL: 2.4 (0%)1, mkdir tempdir: 1.5 (0%)2, create email.txt: 0.4 (0%)2, SMTP MAIL: 2.3 (0%)2, sql-connect: 8 (1%)3, lookup_sql: 3.5 (0%)3, SMTP pre-DATA-flush: 2.0 (0%)3, SMTP DATA: 23 (2%)6, check_init: 0.5 (0%)6, digest_hdr: 8 (1%)7, digest_body_dkim: 14 (1%)8, collect_info: 3.7 (0%)8, gen_mail_id: 4.9 (1%)9, mkdir parts: 2.3 (0%)9, mime_decode: 10 (1%)10, get-file-type1: 10 (1%)11, parts_decode: 0.4 (0%)11, check_header: 1.0 (0%)11, AV-scan-1: 17 (2%)13, lookup_sql: 2.4 (0%)14, lookup_sql: 1.4 (0%)14, lookup_sql: 1.4 (0%)14, lookup_sql: 3.1 (0%)14, lookup_sql: 1.3 (0%)14, lookup_sql: 1.3 (0%)14, spam-wb-list: 1.3 (0%)15, SA msg read: 0.7 (0%)15, SA parse: 6 (1%)15, SA check: 751 (80%)96, decide_mail_destiny: 9 (1%)97, notif-quar: 1.2 (0%)97, quar-hdrs: 3.2 (0%)97, write-header: 3.2 (0%)97, fwd-sql: 2.9 (0%)98, prepare-dsn: 2.3 (0%)98...
Mar  1 15:13:24 ams amavis[47558]: (47558-01) ..., report: 2.1 (0%)98, main_log_entry: 11 (1%)99, sql-update: 3.2 (0%)100, SMTP pre-response: 0.3 (0%)100, SMTP response: 0.3 (0%)100, unlink-1-files: 0.4 (0%)100, rundown: 0.7 (0%)100
Mar  1 15:13:24 ams amavis[47558]: (47558-01) idle_proc, 6: was busy, 905.6 ms, total idle 0.001 s, busy 0.934 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.934 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) ESMTP< QUIT\r\n
Mar  1 15:13:24 ams amavis[47558]: (47558-01) get_deadline switch_to_my_time(rx SMTP QUIT) - deadline in 480.0 s, set to 288.000 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) prolong_timer switch_to_my_time(rx SMTP QUIT): timer 288, was 480, deadline in 480.0 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) ESMTP> 221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel
Mar  1 15:13:24 ams amavis[47558]: (47558-01) switch_to_client_time 480 s, smtp response sent
Mar  1 15:13:24 ams amavis[47558]: (47558-01) SMTP session over, timer stopped
Mar  1 15:13:24 ams amavis[47558]: (47558-01) exiting process_request
Mar  1 15:13:24 ams amavis[47558]: (47558-01) idle_proc, bye: was busy, 3.0 ms, total idle 0.001 s, busy 0.937 s
Mar  1 15:13:24 ams amavis[47558]: (47558-01) load: 100 %, total idle 0.001 s, busy 0.937 s
Mar  1 15:13:28 ams postfix/submission/smtpd[49495]: warning: unknown[187.161.222.144]: SASL LOGIN authentication failed: UGFzc3dvcmQ6
Mar  1 15:13:29 ams postfix/submission/smtpd[49495]: lost connection after AUTH from unknown[187.161.222.144]
Mar  1 15:13:29 ams postfix/submission/smtpd[49495]: disconnect from unknown[187.161.222.144] ehlo=2 starttls=1 auth=0/1 commands=3/4
Mar  1 15:13:31 ams postfix/submission/smtpd[49495]: warning: hostname nsg-corporate-181.230.187.122.airtel.in does not resolve to address 122.187.230.181: Name or service not known
Mar  1 15:13:31 ams postfix/submission/smtpd[49495]: connect from unknown[122.187.230.181]
Mar  1 15:13:32 ams postfix/submission/smtpd[49495]: discarding EHLO keywords: CHUNKING
Mar  1 15:13:36 ams postfix/submission/smtpd[49495]: Anonymous TLS connection established from unknown[122.187.230.181]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Mar  1 15:13:37 ams postfix/submission/smtpd[49495]: discarding EHLO keywords: CHUNKING
Mar  1 15:13:43 ams postfix/submission/smtpd[49495]: warning: unknown[122.187.230.181]: SASL LOGIN authentication failed: UGFzc3dvcmQ6
Mar  1 15:13:44 ams postfix/submission/smtpd[49495]: lost connection after AUTH from unknown[122.187.230.181]
Mar  1 15:13:44 ams postfix/submission/smtpd[49495]: disconnect from unknown[122.187.230.181] ehlo=2 starttls=1 auth=0/1 commands=3/4

4 Reply by Cthulhu

  • Cthulhu
  • Member
  • Offline
  • Registered: 2019-06-04
  • Posts: 907

Re: A lot of clean email with low spam scores is quarantined

blocking contents category is (6)

It is due to file attachment blocking

5 Reply by leonnl

  • leonnl
  • Member
  • Offline
  • Registered: 2024-03-01
  • Posts: 4

Re: A lot of clean email with low spam scores is quarantined

Thank you for the reply, this particular email does not have an attachment. So does a ton of other low spam score emails that are being quarantined.

Where could I find more debug info about this email being flagged because of attachment blocking?

6 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 31,081

Re: A lot of clean email with low spam scores is quarantined

- What's the global, per-domain and per-user spam policy defined in iRedAdmin-Pro?
- Please show us related SQL records in "amavisd.policy" table too.

7 Reply by slovenka (edited by slovenka 2024-03-17 00:52:55)

  • slovenka
  • Member
  • Offline
  • Registered: 2014-12-14
  • Posts: 51

Re: A lot of clean email with low spam scores is quarantined

Can you please check if you have set custom spam scores in iRedAdmin-PRO in System -> Global Spam Policy -> "Mark mail as spam when score is >=" and "Block or quarantine marked spam when score is >=". Empty these fields and test again.
X-Spam-Status: Yes, score=0.43 tag=0 tag2=0 kill=0 <----- tag, tag2 and kill should not be 0, but like default ---->tag=2, tag2=6.2, kill=6.9