Problem with SQL lookup

[Danilo Godec]

Hi,

I recently updated an Postfix/Amavis server from CentOS 6 to CentOS 8,
which brought Amavis from 2.9.1 to 2.12.0. The old server was using SQL
lookup and storage for quarantine, so I transferred the settings to the
new server and at a first glance, things look OK.

However, a few days after the move people started complaining about
missing emails, so I'm not looking into that and what I noticed
initially - that only happens to people, who are listed in the
'amavis.users' table.

So, armed with that information and digging further I found out, that
Amavis always gets spam_tagX_level="0" for these people. So I turned log
level to 11 and here's what I found:

(419033-06) lookup_sql select: SELECT *,users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?,?) ORDER BY users.priority DESC
(419033-06) sql begin, nontransaction
(419033-06) sql: executing clause (7 args): SELECT *,users.id FROM users LEFT JOIN policy ON users.policy_id=policy.id WHERE users.email IN (?,?,?,?,?,?,?) ORDER BY users.priority DESC
(419033-06) lookup_sql(my.user at xyz.xyz.xyz) matches, result=(id=>"1032", priority=>"6", policy_id=>"7", fullname=>-, local=>-, email=>"my.user at xyz.xyz.xyz", id=>"1032", policy_name=>"visoko", virus_lover=>"N", spam_lover=>"N", unchecked_lover=>"N", banned_files_lover=>"N", bad_header_lover=>"N", bypass_virus_checks=>"N", bypass_spam_checks=>"N", bypass_banned_checks=>"Y", bypass_header_checks=>"Y", virus_quarantine_to=>"sql:", spam_quarantine_to=>"sql:", banned_quarantine_to=>"sql:", unchecked_quarantine_to=>-, bad_header_quarantine_to=>"sql:", clean_quarantine_to=>"sql:", archive_quarantine_to=>-, *spam_tag_level=>"0", spam_tag2_level=>"0", spam_tag3_level=>"0",
spam_kill_level=>"0", spam_dsn_cutoff_level=>"0",
spam_quarantine_cutoff_level=>-*, addr_extension_virus=>-, addr_extension_spam=>"Junk", addr_extension_banned=>-, addr_extension_bad_header=>-, warnvirusrecip=>"N", warnbannedrecip=>"N", warnbadhrecip=>"N", newvirus_admin=>"valert at xyz.xyz.xyz",...
(419033-06) ... virus_admin=>"valert at xyz.xyz.xyz", banned_admin=>"valert at xyz.xyz.xyz", bad_header_admin=>"valert at xyz.xyz.xyz", spam_admin=>"valert at xyz.xyz.xyz", spam_subject_tag=>"**SPAM1**", spam_subject_tag2=>"**SPAM2**", spam_subject_tag3=>"**SPAM3**", message_size_limit=>-, banned_rulenames=>-, disclaimer_options=>-, forward_method=>-, sa_userconf=>-, sa_username=>-, id=>"1032")


A little further down the log I see these lines:

(419033-06) lookup_sql_field(spam_tag_level) *rec=0*, "my.user at xyz.xyz.xyz" *result: "0"*
(419033-06) lookup [spam_tag_level] => false, "my.user at xyz.xyz.xyz" matches, *result="0", matching_key="/cached/"*
(419033-06) lookup_sql_field(spam_tag2_level) rec=0, "my.user at xyz.xyz.xyz" result: "0"
(419033-06) lookup [spam_tag2_level] => false, "my.user at xyz.xyz.xyz" matches, result="0", matching_key="/cached/"
(419033-06) lookup_sql_field(spam_tag3_level) rec=0, "my.user at xyz.xyz.xyz" result: "0"
(419033-06) lookup [spam_tag3_level] => false, "my.user at xyz.xyz.xyz" matches, result="0", matching_key="/cached/"
(419033-06) lookup_sql_field(spam_kill_level) rec=0, "my.user at xyz.xyz.xyz" result: "0"
(419033-06) lookup [spam_kill_level] => false, "my.user at xyz.xyz.xyz" matches, result="0", matching_key="/cached/"



Since I also turned on MySQL general log, I could see the exact query
and run it manually - this is the result:

*************************** 1. row ***************************
                          id: 1032
                    priority: 6
                   policy_id: 7
                    fullname: NULL
                       local: NULL
                       email: my.user at xyz.xyz.xyz
                          id: 7
                 policy_name: visoko
                 virus_lover: N
                  spam_lover: N
             unchecked_lover: N
          banned_files_lover: N
            bad_header_lover: N
         bypass_virus_checks: N
          bypass_spam_checks: N
        bypass_banned_checks: Y
        bypass_header_checks: Y
         virus_quarantine_to: sql:
          spam_quarantine_to: sql:
        banned_quarantine_to: sql:
     unchecked_quarantine_to: NULL
    bad_header_quarantine_to: sql:
         clean_quarantine_to: sql:
       archive_quarantine_to: NULL
*spam_tag_level: 8****spam_tag2_level: 10****spam_tag3_level: 15*
             spam_kill_level: 300
       spam_dsn_cutoff_level: 900
spam_quarantine_cutoff_level: NULL
        addr_extension_virus: NULL
         addr_extension_spam: Junk
       addr_extension_banned: NULL
   addr_extension_bad_header: NULL
              warnvirusrecip: N
             warnbannedrecip: N
               warnbadhrecip: N
              newvirus_admin: valert at xyz.xyz.xyz
                 virus_admin: valert at xyz.xyz.xyz
                banned_admin: valert at xyz.xyz.xyz
            bad_header_admin: valert at xyz.xyz.xyz
                  spam_admin: valert at xyz.xyz.xyz
            spam_subject_tag: **SPAM1**
           spam_subject_tag2: **SPAM2**
           spam_subject_tag3: **SPAM3**
          message_size_limit: NULL
            banned_rulenames: NULL
          disclaimer_options: NULL
              forward_method: NULL
                 sa_userconf: NULL
                 sa_username: NULL
                          id: 1032


What's going on here?


  Regards,

   Danilo

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.amavis.org/pipermail/amavis-users/attachments/20201021/5305e931/attachment.htm>