April 4, 2025: iRedMail-1.7.3 has been released.

**Vortex** · 2025-04-16 14:47:57

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Topic: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

==== REQUIRED BASIC INFO OF YOUR IREDMAIL SERVER ====
- iRedMail version (check /etc/iredmail-release):
1.7.2
- Deployed with iRedMail Easy or the downloadable installer?
Downloadable
- Linux/BSD distribution name and version:
Ubuntu 24.04
- Store mail accounts in which backend (LDAP/MySQL/PGSQL):
MySQL/MariaDB
- Web server (Apache or Nginx):
Apache/Nginx
- Manage mail accounts with iRedAdmin-Pro?
No
- [IMPORTANT] Related original log or error message is required if you're experiencing an issue.
====
I've upgraded my server to Ubuntu 24.04. Postfix is not sending mails, staying in the queue.

Amvis service is stopped/half running
smtp-amavis process is showing enabled for max 1 processes

 ubuntu@webmx:/$ sudo systemctl status amavis.service
● amavis.service - LSB: Starts amavisd-new mailfilter
     Loaded: loaded (/etc/init.d/amavis; enabled; preset: enabled)
     Active: active (exited) since Wed 2025-04-16 15:43:33 AEST; 12min ago
       Docs: man:systemd-sysv-generator(8)
    Process: 109283 ExecStart=/etc/init.d/amavis start (code=exited, status=0/SUCCESS)
        CPU: 7ms

Apr 16 15:43:33 webmx systemd[1]: Starting amavis.service - LSB: Starts amavisd-new mailfilter...
Apr 16 15:43:33 webmx systemd[1]: Started amavis.service - LSB: Starts amavisd-new mailfilter.

Process mysql is running:

 ubuntu@webmx:/$ systemctl status mariadb.service
● mariadb.service - MariaDB 10.11.11 database server
     Loaded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; preset: enabled)
    Drop-In: /etc/systemd/system/mariadb.service.d
             └─migrated-from-my.cnf-settings.conf, override.conf
     Active: active (running) since Wed 2025-04-16 14:18:14 AEST; 1h 39min ago
       Docs: man:mariadbd(8)
             https://mariadb.com/kb/en/library/systemd/
   Main PID: 82485 (mariadbd)
     Status: "Taking your SQL requests now..."
      Tasks: 21 (limit: 15141)
     Memory: 143.1M (peak: 143.5M)
        CPU: 1.339s
     CGroup: /system.slice/mariadb.service
             └─82485 /usr/sbin/mariadbd

Apr 16 14:18:14 webmx mariadbd[82485]: 2025-04-16 14:18:14 0 [Note] Plugin 'FEEDBACK' is disabled.
Apr 16 14:18:14 webmx mariadbd[82485]: 2025-04-16 14:18:14 0 [Warning] You need to use --log-bin to make --expire-logs-days or --binlog-expire-logs-seconds work.
Apr 16 14:18:14 webmx mariadbd[82485]: 2025-04-16 14:18:14 0 [Note] Server socket created on IP: '127.0.0.1'.
Apr 16 14:18:14 webmx mariadbd[82485]: 2025-04-16 14:18:14 0 [Note] InnoDB: Buffer pool(s) load completed at 250416 14:18:14
Apr 16 14:18:14 webmx mariadbd[82485]: 2025-04-16 14:18:14 0 [Note] /usr/sbin/mariadbd: ready for connections.
Apr 16 14:18:14 webmx mariadbd[82485]: Version: '10.11.11-MariaDB-0ubuntu0.24.04.2'  socket: '/run/mysqld/mysqld.sock'  port: 3306  Ubuntu 24.04
Apr 16 14:18:14 webmx systemd[1]: Started mariadb.service - MariaDB 10.11.11 database server.
Apr 16 14:18:14 webmx /etc/mysql/debian-start[82503]: Upgrading MariaDB tables if necessary.
Apr 16 14:18:14 webmx /etc/mysql/debian-start[82507]: /usr/bin/mariadb-upgrade: the '--basedir' option is always ignored
Apr 16 14:18:14 webmx /etc/mysql/debian-start[82519]: Triggering myisam-recover for all MyISAM tables and aria-recover for all Aria tables

Postfix status

 ubuntu@webmx:/$ sudo systemctl status postfix.service
● postfix.service - Postfix Mail Transport Agent
     Loaded: loaded (/usr/lib/systemd/system/postfix.service; enabled; preset: enabled)
     Active: active (exited) since Wed 2025-04-16 16:52:54 AEST; 8s ago
       Docs: man:postfix(1)
    Process: 130619 ExecStart=/bin/true (code=exited, status=0/SUCCESS)
   Main PID: 130619 (code=exited, status=0/SUCCESS)
        CPU: 2ms

Apr 16 16:52:54 webmx systemd[1]: Starting postfix.service - Postfix Mail Transport Agent...
Apr 16 16:52:54 webmx systemd[1]: Finished postfix.service - Postfix Mail Transport Agent.

Postfix is running - pickup -l -t unix -u -o content_filter=smtp-amavis:[127.0.0.1]:10026
Postfix is queueing mail with a status of connect to 127.0.0.1[127.0.0.1]:10024: Connection refused

All was in good order before the upgrade. I did get some Grub errors at the finish, however all else seems fine other than Amavis and Postfix not connecting to mysql. Is suspect mysql.

These are some mail.log entries:

webmx amavis[32455]: (32455-15) NOTICE: reconnecting in response to: err=2013, HY000, DBD::mysql::st execute failed: Lost connection to MySQL server during query at (eval 122) line 173.
webmx postfix/trivial-rewrite[115054]: warning: sender_dependent_default_transport_maps lookup failure

mail.warn log:

Apr 16 10:41:40 webmx postfix/trivial-rewrite[115054]: warning: pcre:/etc/postfix/sdd_transport.pcre is unavailable. unsupported dictionary type: pcre
Apr 16 10:41:40 webmx postfix/trivial-rewrite[115054]: warning: pcre:/etc/postfix/sdd_transport.pcre lookup error for ""<>""
Apr 16 10:41:40 webmx postfix/trivial-rewrite[115054]: warning: sender_dependent_default_transport_maps lookup failure

Mail.err log:

Apr 16 10:26:26 webmx postfix/submission/smtpd[119977]: error: unsupported dictionary type: pcre
Apr 16 10:26:26 webmx postfix/submission/smtpd[119977]: error: unsupported dictionary type: pcre
Apr 16 10:28:11 webmx postfix/smtpd[124331]: error: unsupported dictionary type: pcre
Apr 16 10:28:11 webmx postfix/smtpd[124331]: error: unsupported dictionary type: pcre
Apr 16 10:28:11 webmx postfix/smtpd[124331]: error: unsupported dictionary type: pcre
Apr 16 10:34:31 webmx postfix/proxymap[115773]: error: unsupported dictionary type: mysql
Apr 16 10:40:07 webmx postfix/proxymap[115773]: error: unsupported dictionary type: mysql
Apr 16 10:40:07 webmx postfix/proxymap[115773]: fatal: too many errors - program terminated

If anyone has any ideas they will be most welcome. TIA.

----

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

**ZhangHuangbin** · 2025-04-16 14:57:13

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 31,361

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Run "amavisd-new debug" manually, any error on console?

**Vortex** · 2025-04-16 15:11:36

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Thank you.

No, there's a problem there. Neither amavisd-new debug or amavis-new debug in both cases the error is "command not found"

I've also noted now the Roundcube isn't working. But iRedAdmin is. I haven't yet looked into why Roundcube isn't working. The error is a Roundcube generated error: "An internal error has occurred. Your request cannot be processed at this time."

**ZhangHuangbin** · 2025-04-16 15:20:47

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 31,361

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

- Then try command "amavisd".
- Also, FYI https://docs.iredmail.org/upgrade.ubunt … 24.04.html

**Vortex** · 2025-04-16 15:30:55

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Thanks. Brain fade too busy trying to find the prob... That worked.

ubuntu@webmx:/$ sudo amavisd debug
Apr 16 17:26:21.177 mx.xxxx.com.au /usr/sbin/amavisd[11066]: logging initialized, log level 0, syslog: amavis.mail
Apr 16 17:26:21.177 mx.xxxx.com.au /usr/sbin/amavisd[11066]: sd_notify (no socket): STATUS=Config files have been read, modules loaded.
Apr 16 17:26:21.177 mx.xxxx.com.au /usr/sbin/amavisd[11066]: starting. /usr/sbin/amavisd at mx.vbox.com.au amavis-2.13.0 (20230106), Unicode aware, LANG="C.UTF-8"
Apr 16 17:26:21.177 mx.xxxx.com.au /usr/sbin/amavisd[11066]: perl=5.038002, user=, EUID: 117 (117);  group=(), EGID: 123 123 (123 123)
Apr 16 17:26:21.293 mx.xxxx.com.au /usr/sbin/amavisd[11066]: INFO: no optional modules: utf8_heavy.pl unicore::To::Lower.pl unicore::To::Upper.pl unicore::To::Fold.pl unicore::To::Title.pl unicore::To::Digit.pl unicore::lib::Nt::De.pl unicore::Heavy.pl Unix::Getrusage
Apr 16 17:26:21.293 mx.xxxx.com.au /usr/sbin/amavisd[11066]: SpamControl: attempting to load scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin
Apr 16 17:26:21.293 mx.xxxx.com.au /usr/sbin/amavisd[11066]: SpamControl: scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin
Apr 16 17:26:21.657 mx.xxxx.com.au /usr/sbin/amavisd[11066]: INFO: SA version: 4.0.0, 4.000000, no optional modules: Mail::SpamAssassin::AutoWhitelist Encode::Detect Mail::SpamAssassin::Plugin::Hashcash Mail::SpamAssassin::Plugin::WhiteListSubject Image::Info Image::Info::GIF Image::Info::JPEG Image::Info::PNG Image::Info::BMP Image::Info::TIFF
Apr 16 17:26:21.658 mx.xxxx.com.au /usr/sbin/amavisd[11066]: SpamControl: init_pre_chroot on SpamAssassin done
Apr 16 17:26:21.658 mx.xxxx.com.au /usr/sbin/amavisd[11066]: socket module IO::Socket::IP, protocol families available: INET, INET6
Apr 16 17:26:21.658 mx.xxxx.com.au /usr/sbin/amavisd[11066]: will bind to /var/run/amavis/amavisd.socket|unix, 127.0.0.1:10024/tcp, 127.0.0.1:10026/tcp, 127.0.0.1:10027/tcp, 127.0.0.1:9998/tcp
Apr 16 17:26:21.658 mx.xxxx.com.au /usr/sbin/amavisd[11066]: sd_notify (no socket): STATUS=Transferring control to Net::Server.
Apr 16 17:26:21.659 mx.xxxx.com.au /usr/sbin/amavisd[11066]: (!)Net::Server: 2025/04/16-17:26:21 Couldn't open pid file "/var/run/amavis/amavisd.pid" [No such file or directory].\n\n  at line 177 in file /usr/share/perl5/Net/Server.pm
Apr 16 17:26:21.659 mx.xxxx.com.au /usr/sbin/amavisd[11066]: sd_notify (no socket): STOPPING=1\nSTATUS=Server rundown, notifying child processes.
Apr 16 17:26:21.659 mx.xxxx.com.au /usr/sbin/amavisd[11066]: Net::Server: 2025/04/16-17:26:21 Server closing!
Apr 16 17:26:21.659 mx.xxxx.com.au /usr/sbin/amavisd[11066]: sd_notify (no socket): STATUS=Child processes have been stopped.

I've seen this in other logs... the file doesn't exist that's true

 /usr/sbin/amavisd[11066]: (!)Net::Server: 2025/04/16-17:26:21 Couldn't open pid file "/var/run/amavis/amavisd.pid" [No such file or directory].\n\n  at line 177 in file /usr/share/perl5/Net/Server.pm

I'll also go and check the link. I wasn't aware of that document. So I didn't do the changes, I'll do than now.

**Vortex** · 2025-04-16 16:12:05

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Ok, I've done all the updates now. A point. Is it necesssary for php8.3 to be selected apache module. I have a need for php7.4 for a web app. The default php ver is 8.2.8

root@webmx:/home# php -v
PHP 8.2.8 (cli) (built: Jul  8 2023 0
7:09:59) (NTS)
Copyright (c) The PHP Group
Zend Engine v4.2.8, Copyright (c) Zend Technologies
    with Zend OPcache v8.2.8, Copyright (c), by Zend Technologies

With php8.2 there is a Roundcube error, I just discovered while checking php versions.

root@webmx:/home# sudo systemctl status php8.2-fpm.service
● php8.2-fpm.service - The PHP 8.2 FastCGI Process Manager
     Loaded: loaded (/usr/lib/systemd/system/php8.2-fpm.service; enabled; preset: enabled)
     Active: active (running) since Wed 2025-04-16 18:01:15 AEST; 8min ago
       Docs: man:php-fpm8.2(8)
    Process: 26168 ExecStartPost=/usr/lib/php/php-fpm-socket-helper install /run/php/php-fpm.sock /etc/php/8.2/fpm/pool.d/www.conf 82 (code=exited, status=0/SUCCESS)
   Main PID: 26165 (php-fpm8.2)
     Status: "Processes active: 0, idle: 2, Requests: 2, slow: 0, Traffic: 0req/sec"
      Tasks: 3 (limit: 2294)
     Memory: 37.3M (peak: 38.8M)
        CPU: 272ms
     CGroup: /system.slice/php8.2-fpm.service
             ├─26165 "php-fpm: master process (/etc/php/8.2/fpm/php-fpm.conf)"
             ├─26166 "php-fpm: pool www"
             └─26167 "php-fpm: pool www"

Apr 16 18:02:52 webmx roundcube[26166]: #5 /var/www/html/vbox.com.au/roundcubemail/program/lib/Roundcube/session/db.php(113): rcube_db->query()
Apr 16 18:02:52 webmx roundcube[26166]: #6 [internal function]: rcube_session_db->read()
Apr 16 18:02:52 webmx roundcube[26166]: #7 /var/www/html/vbox.com.au/roundcubemail/program/lib/Roundcube/rcube_session.php(141): session_start()
Apr 16 18:02:52 webmx roundcube[26166]: #8 /var/www/html/vbox.com.au/roundcubemail/program/lib/Roundcube/rcube.php(495): rcube_session->start()
Apr 16 18:02:52 webmx roundcube[26166]: #9 /var/www/html/vbox.com.au/roundcubemail/program/include/rcmail.php(649): rcube->session_init()
Apr 16 18:02:52 webmx roundcube[26166]: #10 /var/www/html/vbox.com.au/roundcubemail/program/include/rcmail.php(118): rcmail->session_init()
Apr 16 18:02:52 webmx roundcube[26166]: #11 /var/www/html/vbox.com.au/roundcubemail/program/include/rcmail.php(93): rcmail->startup()
Apr 16 18:02:52 webmx roundcube[26166]: #12 /var/www/html/vbox.com.au/roundcubemail/index.php(43): rcmail::get_instance()
Apr 16 18:02:52 webmx roundcube[26166]: #13 {main}
Apr 16 18:02:52 webmx roundcube[26166]:   thrown in /var/www/html/vbox.com.au/roundcubemail/program/lib/Roundcube/db/mysql.php on line 129

It's getting deeper

**Vortex** · 2025-04-16 17:47:34

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

I've done some digging... I'm fairly confident the problem is connecting to mysql. However, I'm at a loss as to how to debug that, locate the issue a fix.

ubuntu@webmx:/$ dpkg --get-selections | grep mysql
dovecot-mysql                                   install
libdbd-mysql-perl:amd64                         install
libmysqlclient21:amd64                          install
mysql-common                                    install
php-mysql                                       install
php7.2-mysql                                    deinstall
php7.4-mysql                                    install
php8.2-mysql                                    deinstall
php8.3-mysql                                    install
postfix-mysql                                   install
python3-pymysql                                 install

php7.4 is needed for a web app. Current active php is php8.2 Others are not required.

And this

ubuntu@webmx:/$ telnet amavisd 3306
Server lookup failure:  amavisd:3306, Temporary failure in name resolution

Plus this

postfix/amavis/smtp[67112]: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused
ubuntu@webmx:/$ sudo telnet 127.0.0.1
Trying 127.0.0.1...
telnet: Unable to connect to remote host: Connection refused

Need help please.

**ZhangHuangbin** · 2025-04-16 19:23:24

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 31,361

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Try this:

mkdir -p /var/run/amavis
chown amavis:amavis /var/run/amavis
amavisd debug

**Vortex** · 2025-04-16 19:52:34

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Thank you. Done that. Postfix still queueing. Many of the errors I see point to mysql. The Mariadb was upgraded as part of the OS upgrade. Unfortunaty I cannt find where to locte the issue. THnkyou so much for your help with this issue.

The result of amavisd debug is huge I need to do it in 2 parts due to exceeding post length...

Part 1.

ubuntu@webmx:/$ sudo amavisd debug
Apr 16 21:39:22.658 mx.xxxx.com.au /usr/sbin/amavisd[97926]: logging initialized, log level 0, syslog: amavis.mail
Apr 16 21:39:22.659 mx.xxxx.com.au /usr/sbin/amavisd[97926]: sd_notify (no socket): STATUS=Config files have been read, modules loaded.
Apr 16 21:39:22.659 mx.xxxx.com.au /usr/sbin/amavisd[97926]: starting. /usr/sbin/amavisd at mx.xxxx.com.au amavis-2.13.0 (20230106), Unicode aware, LANG="C.UTF-8"
Apr 16 21:39:22.659 mx.xxxx.com.au /usr/sbin/amavisd[97926]: perl=5.038002, user=, EUID: 117 (117);  group=(), EGID: 123 123 (123 123)
Apr 16 21:39:22.741 mx.xxxx.com.au /usr/sbin/amavisd[97926]: INFO: no optional modules: utf8_heavy.pl unicore::To::Lower.pl unicore::To::Upper.pl unicore::To::Fold.pl unicore::To::Title.pl unicore::To::Digit.pl unicore::lib::Nt::De.pl unicore::Heavy.pl Unix::Getrusage
Apr 16 21:39:22.741 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SpamControl: attempting to load scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin
Apr 16 21:39:22.741 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SpamControl: scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin
Apr 16 21:39:23.089 mx.xxxx.com.au /usr/sbin/amavisd[97926]: INFO: SA version: 4.0.0, 4.000000, no optional modules: Mail::SpamAssassin::AutoWhitelist Encode::Detect Mail::SpamAssassin::Plugin::Hashcash Mail::SpamAssassin::Plugin::WhiteListSubject Image::Info Image::Info::GIF Image::Info::JPEG Image::Info::PNG Image::Info::BMP Image::Info::TIFF
Apr 16 21:39:23.090 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SpamControl: init_pre_chroot on SpamAssassin done
Apr 16 21:39:23.090 mx.xxxx.com.au /usr/sbin/amavisd[97926]: socket module IO::Socket::IP, protocol families available: INET, INET6
Apr 16 21:39:23.090 mx.xxxx.com.au /usr/sbin/amavisd[97926]: will bind to /var/run/amavis/amavisd.socket|unix, 127.0.0.1:10024/tcp, 127.0.0.1:10026/tcp, 127.0.0.1:10027/tcp, 127.0.0.1:9998/tcp
Apr 16 21:39:23.090 mx.xxxx.com.au /usr/sbin/amavisd[97926]: sd_notify (no socket): STATUS=Transferring control to Net::Server.
Apr 16 21:39:23.091 mx.xxxx.com.au /usr/sbin/amavisd[97926]: sd_notify (no socket): STATUS=Preparing to bind sockets.
Apr 16 21:39:23.091 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Net::Server: 2025/04/16-21:39:23 Amavis (type Net::Server) starting! pid(97926)
Apr 16 21:39:23.097 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Net::Server: Binding to UNIX socket file "/var/run/amavis/amavisd.socket"
Apr 16 21:39:23.097 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 with IPv4
Apr 16 21:39:23.097 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Net::Server: Binding to TCP port 10026 on host 127.0.0.1 with IPv4
Apr 16 21:39:23.098 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Net::Server: Binding to TCP port 10027 on host 127.0.0.1 with IPv4
Apr 16 21:39:23.098 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Net::Server: Binding to TCP port 9998 on host 127.0.0.1 with IPv4
Apr 16 21:39:23.099 mx.xxxx.com.au /usr/sbin/amavisd[97926]: sd_notify (no socket): STATUS=Sockets bound, checking user and group.
Apr 16 21:39:23.099 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Net::Server: Group Not Defined.  Defaulting to EGID '123 123'
Apr 16 21:39:23.099 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Net::Server: User Not Defined.  Defaulting to EUID '117'
Apr 16 21:39:23.099 mx.xxxx.com.au /usr/sbin/amavisd[97926]: sd_notify (no socket): STATUS=The rest of pre-fork init, finding helper programs.
Apr 16 21:39:23.100 mx.xxxx.com.au /usr/sbin/amavisd[97926]: after_chroot_init: EUID: 117 (117);  EGID: 123 123 (123 123)
Apr 16 21:39:23.100 mx.xxxx.com.au /usr/sbin/amavisd[97926]: config files read: /usr/share/amavis/conf.d/10-debian_scripts, /usr/share/amavis/conf.d/20-package, /etc/amavis/conf.d/01-debian, /etc/amavis/conf.d/05-domain_id, /etc/amavis/conf.d/05-node_id, /etc/amavis/conf.d/15-av_scanners, /etc/amavis/conf.d/15-content_filter_mode, /etc/amavis/conf.d/20-debian_defaults, /etc/amavis/conf.d/21-ubuntu_defaults, /etc/amavis/conf.d/25-amavis_helpers, /etc/amavis/conf.d/30-template_localization, /etc/amavis/conf.d/40-policy_banks, /etc/amavis/conf.d/50-user
Apr 16 21:39:23.106 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Amavis::Conf        2.412
Apr 16 21:39:23.106 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Amavis::Conf        2.412
Apr 16 21:39:23.106 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Archive::Zip        1.68
Apr 16 21:39:23.106 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Compress::Raw::Zlib 2.204001
Apr 16 21:39:23.106 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Compress::Zlib      2.204
Apr 16 21:39:23.106 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Crypt::OpenSSL::RSA 0.33
Apr 16 21:39:23.107 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module DBD::mysql          4.052
Apr 16 21:39:23.107 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module DBI                 1.643
Apr 16 21:39:23.107 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module DB_File             1.858
Apr 16 21:39:23.107 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Digest::MD5         2.58_01
Apr 16 21:39:23.107 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Digest::SHA         6.04
Apr 16 21:39:23.107 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Encode              3.19
Apr 16 21:39:23.107 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module File::Temp          0.2311
Apr 16 21:39:23.107 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module IO::Socket::IP      0.4101
Apr 16 21:39:23.107 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module IO::Socket::SSL     2.085
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module MIME::Entity        5.514
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module MIME::Parser        5.514
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module MIME::Tools         5.514
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Mail::DKIM::Signer  1.20230212
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Mail::DKIM::Verifier 1.20230212
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Mail::Header        2.21
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Mail::Internet      2.21
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Mail::SPF           3.20240206
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Mail::SpamAssassin  4.000000
Apr 16 21:39:23.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Net::DNS            1.44
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Net::LibIDN         0.12
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Net::Patricia       1.22
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Net::SSLeay         1.94
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Net::Server         2.014
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module NetAddr::IP         4.079
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Razor2::Client::Version 2.84
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Scalar::Util        1.63
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Socket              2.036
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Socket6             0.29
Apr 16 21:39:23.109 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Time::HiRes         1.9775
Apr 16 21:39:23.110 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module URI                 5.27
Apr 16 21:39:23.110 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Module Unix::Syslog        1.1
Apr 16 21:39:23.110 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SQL base code        loaded
Apr 16 21:39:23.110 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SQL::Log code        loaded
Apr 16 21:39:23.110 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SQL::Quarantine      loaded
Apr 16 21:39:23.110 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Lookup::SQL code     loaded
Apr 16 21:39:23.111 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Lookup::LDAP code    NOT loaded
Apr 16 21:39:23.111 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found $file            at /usr/bin/file
Apr 16 21:39:23.111 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found $altermime       at /usr/bin/altermime
Apr 16 21:39:23.111 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Internal decoder for .mail
Apr 16 21:39:23.111 mx.xxxx.com.au /usr/sbin/amavisd[97926]: No ext program for   .F, tried: unfreeze, freeze -d, melt, fcat
Apr 16 21:39:23.111 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .Z    at /usr/bin/uncompress
Apr 16 21:39:23.111 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .gz   at /usr/bin/gzip -d
Apr 16 21:39:23.111 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Internal decoder for .gz   (backup, not used)
Apr 16 21:39:23.112 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .bz2  at /usr/bin/bzip2 -d
Apr 16 21:39:23.112 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .xz   at /usr/bin/xz -dc
Apr 16 21:39:23.112 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .lzma at /usr/bin/xz -dc --format=lzma
Apr 16 21:39:23.112 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .lrz  at /usr/bin/lrzip -q -k -d -o -
Apr 16 21:39:23.112 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .lzo  at /usr/bin/lzop -d
Apr 16 21:39:23.113 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .lz4  at /usr/bin/lz4c -d
Apr 16 21:39:23.113 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .rpm  at /usr/bin/rpm2cpio
Apr 16 21:39:23.113 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .cpio at /usr/bin/pax
Apr 16 21:39:23.113 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .tar  at /usr/bin/pax
Apr 16 21:39:23.115 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .deb  at /usr/bin/ar
Apr 16 21:39:23.116 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .rar  at /usr/bin/unrar
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .arj  at /usr/bin/arj
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .arc  at /usr/bin/nomarch
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: No ext program for   .zoo, tried: zoo, unzoo
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .cab  at /usr/bin/cabextract
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Internal decoder for .tnef
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .zip  at /usr/bin/7za
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .kmz  at /usr/bin/7za
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Internal decoder for .zip  (backup, not used)
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Internal decoder for .kmz  (backup, not used)
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .7z   at /usr/bin/7zr
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .gz   at /usr/bin/7za (backup, not used)
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .bz2  at /usr/bin/7za (backup, not used)
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .Z    at /usr/bin/7za (backup, not used)
Apr 16 21:39:23.117 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .tar  at /usr/bin/7za (backup, not used)
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .xz   at /usr/bin/7z (backup, not used)
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .lzma at /usr/bin/7z (backup, not used)
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .jar  at /usr/bin/7z
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .cpio at /usr/bin/7z (backup, not used)
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .arj  at /usr/bin/7z (backup, not used)
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .rar  at /usr/bin/7z (backup, not used)
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .swf  at /usr/bin/7z
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .lha  at /usr/bin/7z
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .iso  at /usr/bin/7z
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .cab  at /usr/bin/7z (backup, not used)
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .deb  at /usr/bin/7z (backup, not used)
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .rpm  at /usr/bin/7z (backup, not used)
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found decoder for    .exe  at /usr/bin/unrar; /usr/bin/arj
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: No decoder for       .F
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: No decoder for       .zoo
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Found primary av scanner clamav-clamscan at /usr/bin/clamscan
Apr 16 21:39:23.118 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Using internal spam scanner code for SpamAssassin
Apr 16 21:39:23.119 mx.xxxx.com.au /usr/sbin/amavisd[97926]: initializing Mail::SpamAssassin (0)
Apr 16 21:39:23.119 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SpamAssassin debug facilities: info
Apr 16 21:39:23.992 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SA info: zoom: able to use 388/388 'body_0' compiled rules (100%)
Apr 16 21:39:24.515 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SpamAssassin loaded plugins: AskDNS, AutoLearnThreshold, Bayes, BodyEval, Check, DKIM, DMARC, DNSEval, FreeMail, HTMLEval, HTTPSMismatch, HashBL, HeaderEval, ImageInfo, MIMEEval, MIMEHeader, Pyzor, Razor2, RelayEval, ReplaceTags, Rule2XSBody, SPF, SpamCop, URIDNSBL, URIDetail, URIEval, VBounce, WLBLEval, WelcomeListSubject
Apr 16 21:39:24.515 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SpamControl: init_pre_fork on SpamAssassin done
Apr 16 21:39:24.516 mx.xxxx.com.au /usr/sbin/amavisd[97926]: extra modules loaded after daemonizing/chrooting: /etc/perl/Net/libnet.cfg, Class/Inspector.pm, Compress/Raw/Bzip2.pm, Config/Tiny.pm, Email/Simple.pm, Email/Simple/Creator.pm, Email/Simple/Header.pm, English.pm, File/ShareDir.pm, HTTP/Tiny.pm, IO/Compress/Adapter/Bzip2.pm, IO/Compress/Adapter/Identity.pm, IO/Compress/Bzip2.pm, IO/Compress/Zip.pm, IO/Compress/Zip/Constants.pm, IO/Uncompress/Adapter/Bunzip2.pm, IO/Uncompress/Adapter/Identity.pm, IO/Uncompress/Unzip.pm, Mail/DKIM/ARC/MessageSignature.pm, Mail/DKIM/ARC/Seal.pm, Mail/DKIM/ARC/Verifier.pm, Mail/DMARC.pm, Mail/DMARC/Base.pm, Mail/DMARC/Policy.pm, Mail/DMARC/PurePerl.pm, Mail/DMARC/Report.pm, Mail/DMARC/Report/Aggregate.pm, Mail/DMARC/Report/Aggregate/Metadata.pm, Mail/DMARC/Report/Aggregate/Record.pm, Mail/DMARC/Report/Aggregate/Record/Auth_Results.pm, Mail/DMARC/Report/Aggregate/Record/Auth_Results/DKIM.pm, Mail/DMARC/Report/Aggregate/Record/Auth_Results/SPF.pm, Mail/DMARC/Report/Aggregate/Record/Identifiers.pm, Mail/DMARC/Report/Aggregate/Record/Row.pm, Mail/DMARC/Report/Aggregate/Record/Row/Policy_Evaluated.pm, Mail/DMARC/Report/Receive.pm, Mail/DMARC/Report/Send.pm, Mail/DMARC/Report/Send/HTTP.pm, Mail/DMARC/Report/Send/SMTP.pm, Mail/DMARC/Report/Store.pm, Mail/DMARC/Report/URI.pm, Mail/DMARC/Result.pm, Mail/DMARC/Result/Reason.pm, Mail/SpamAssassin/BayesStore/MySQL.pm, Mail/SpamAssassin/BayesStore/SQL.pm, Mail/SpamAssassin/CompiledRegexps/body_0.pm, Mail/SpamAssassin/CompiledRegexps/body_neg2000.pm, Mail/SpamAssassin/Logger/Amavislog.pm, Mail/SpamAssassin/Plugin/DMARC.pm, Mail/SpamAssassin/Plugin/FreeMail.pm, Mail/SpamAssassin/Plugin/HashBL.pm, Mail/SpamAssassin/Plugin/SpamCop.pm, Mail/SpamAssassin/Plugin/WelcomeListSubject.pm, Math/BigInt.pm, Math/BigInt/Calc.pm, Math/BigInt/Lib.pm, Net/Cmd.pm, Net/Config.pm, Net/IP.pm, Net/SMTP.pm, Regexp/Common.pm, Regexp/Common/net.pm, XML/LibXML.pm, XML/LibXML/AttributeHash.pm, XML/LibXML/Boolean.pm, XML/LibXML/Error.pm, XML/LibXML/Literal.pm, XML/LibXML/NodeList.pm, XML/LibXML/Number.pm, XML/LibXML/XPathContext.pm, XML/SAX/Exception.pm
Apr 16 21:39:24.517 mx.xxxx.com.au /usr/sbin/amavisd[97926]: sd_notify (no socket): READY=1\nSTATUS=Initialization done.
Apr 16 21:40:56.832 mx.xxxx.com.au /usr/sbin/amavisd[97926]: Net::Server: 2025/04/16-21:40:56 CONNECT TCP Peer: "[127.0.0.1]:41022" Local: "[127.0.0.1]:10024"
Apr 16 21:40:56.833 mx.xxxx.com.au /usr/sbin/amavisd[97926]: post_accept_hook: invoking child_init_hook which was skipped
Apr 16 21:40:56.833 mx.xxxx.com.au /usr/sbin/amavisd[97926]: entered child_init_hook
Apr 16 21:40:56.833 mx.xxxx.com.au /usr/sbin/amavisd[97926]: storage and lookups will use the same connection to SQL
Apr 16 21:40:56.834 mx.xxxx.com.au /usr/sbin/amavisd[97926]: SpamControl: init_child on SpamAssassin done
Apr 16 21:40:56.834 mx.xxxx.com.au /usr/sbin/amavisd[97926]: loaded base policy bank
Apr 16 21:40:56.835 mx.xxxx.com.au /usr/sbin/amavisd[97926]: lookup_ip_acl (inet_acl) arr.obj: key="127.0.0.1" matches "127.0.0.1", result=1
Apr 16 21:40:56.835 mx.xxxx.com.au /usr/sbin/amavisd[97926]: process_request: fileno sock=12, STDIN=0, STDOUT=1
Apr 16 21:40:56.835 mx.xxxx.com.au /usr/sbin/amavisd[97926]: get_deadline switch_to_my_time(new request) - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.835 mx.xxxx.com.au /usr/sbin/amavisd[97926]: prolong_timer switch_to_my_time(new request): timer 288, was 0, deadline in 480.0 s
Apr 16 21:40:56.836 mx.xxxx.com.au /usr/sbin/amavisd[97926]: process_request: suggested_protocol="" on a TCP socket
Apr 16 21:40:56.836 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) SMTP> 220 [127.0.0.1] ESMTP amavis service ready
Apr 16 21:40:56.836 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, smtp response sent
Apr 16 21:40:56.836 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 4: was busy, 2.4 ms, total idle 0.000 s, busy 0.002 s
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp readline: read 21 bytes, new size: 21
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.000 s, busy 0.002 s
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) SMTP< EHLO mx.xxxx.com.au\r\n
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline switch_to_my_time(rx SMTP EHLO) - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer switch_to_my_time(rx SMTP EHLO): timer 288, was 480, deadline in 480.0 s
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250-[127.0.0.1]
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250-VRFY
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250-PIPELINING
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250-SIZE
Apr 16 21:40:56.837 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250-ENHANCEDSTATUSCODES
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250-8BITMIME
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250-SMTPUTF8
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250-DSN
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250 XFORWARD NAME ADDR PORT PROTO HELO IDENT SOURCE
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, smtp response sent
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 6: was busy, 1.3 ms, total idle 0.000 s, busy 0.004 s
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp readline: read 267 bytes, new size: 267
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 5: was idle, 0.3 ms, total idle 0.001 s, busy 0.004 s
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP< XFORWARD NAME=mx.parkpanthers.live ADDR=162.248.102.44 PORT=40308\r\n
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.838 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 288, was 480, deadline in 480.0 s
Apr 16 21:40:56.839 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250 2.5.0 Ok XFORWARD
Apr 16 21:40:56.839 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, smtp response sent
Apr 16 21:40:56.839 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 6: was busy, 1.2 ms, total idle 0.001 s, busy 0.005 s
Apr 16 21:40:56.839 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 5: was idle, 0.0 ms, total idle 0.001 s, busy 0.005 s
Apr 16 21:40:56.839 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP< XFORWARD PROTO=ESMTP HELO=mx.parkpanthers.live IDENT=4ZczcS41Rzz9dpX SOURCE=REMOTE\r\n
Apr 16 21:40:56.839 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.839 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 288, was 480, deadline in 480.0 s
Apr 16 21:40:56.839 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250 2.5.0 Ok XFORWARD
Apr 16 21:40:56.840 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, smtp response sent
Apr 16 21:40:56.840 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 6: was busy, 0.2 ms, total idle 0.001 s, busy 0.005 s
Apr 16 21:40:56.840 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 5: was idle, 0.0 ms, total idle 0.001 s, busy 0.005 s
Apr 16 21:40:56.840 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP< MAIL FROM:<markslatter676@gmail.com> SIZE=3699\r\n
Apr 16 21:40:56.840 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline switch_to_my_time(rx SMTP MAIL) - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.840 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer switch_to_my_time(rx SMTP MAIL): timer 288, was 480, deadline in 480.0 s
Apr 16 21:40:56.840 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) check_mail_begin_task: task_count=1
Apr 16 21:40:56.840 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) TempDir::prepare_dir: created directory /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w
Apr 16 21:40:56.841 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) TempDir::prepare_file: creating file /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w/email.txt
Apr 16 21:40:56.841 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) TempDir::prepare_file: layers: unix,perlio
Apr 16 21:40:56.841 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_ip_acl (client_ipaddr_policy) arr.obj: key="162.248.102.44", no match
Apr 16 21:40:56.841 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [debug_sender] => undef, "markslatter676@gmail.com" does not match
Apr 16 21:40:56.842 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) mesage size set to a declared size 3699
Apr 16 21:40:56.842 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250 2.1.0 Sender <markslatter676@gmail.com> OK
Apr 16 21:40:56.842 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, smtp response sent
Apr 16 21:40:56.842 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 6: was busy, 2.3 ms, total idle 0.001 s, busy 0.007 s
Apr 16 21:40:56.842 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.001 s, busy 0.007 s
Apr 16 21:40:56.842 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP< RCPT TO:<info@vortex.com.au> ORCPT=rfc822;info@vortex.com.au\r\n
Apr 16 21:40:56.842 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline switch_to_my_time(rx SMTP RCPT) - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.842 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer switch_to_my_time(rx SMTP RCPT): timer 288, was 480, deadline in 480.0 s
Apr 16 21:40:56.842 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup => undef, "info@vortex.com.au", no lookup tables
Apr 16 21:40:56.843 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="1"
Apr 16 21:40:56.843 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [local_domains] => true,  "info@vortex.com.au" matches, result="1", matching_key="(constant:1)"
Apr 16 21:40:56.843 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) query_keys: info@vortex.com.au, info, @vortex.com.au, @.vortex.com.au, @.com.au, @.au, @.
Apr 16 21:40:56.843 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql sel_policy "info@vortex.com.au", query args: [info@vortex.com.au,-3], [info,-3], [@vortex.com.au,-3], [@.vortex.com.au,-3], [@.com.au,-3], [@.au,-3], [@.,-3]
Apr 16 21:40:56.843 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-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
Apr 16 21:40:56.843 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql begin, nontransaction
Apr 16 21:40:56.843 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Connecting to SQL database server
Apr 16 21:40:56.843 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) connect_to_sql: trying 'DBI:mysql:database=amavisd;host=127.0.0.1;port=3306'
Apr 16 21:40:56.844 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) connect_to_sql: 'DBI:mysql:database=amavisd;host=127.0.0.1;port=3306' succeeded
Apr 16 21:40:56.844 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql: preparing and executing (7 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
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql: "info@vortex.com.au" matches catchall, local=>undef
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql(info@vortex.com.au) matches, result=(id=>"1", priority=>"0", policy_id=>"1", email=>"@.", fullname=>-, id=>"1", policy_name=>"@.", virus_lover=>"N", spam_lover=>"Y", unchecked_lover=>-, banned_files_lover=>"N", bad_header_lover=>"Y", bypass_virus_checks=>"N", bypass_spam_checks=>"N", bypass_banned_checks=>"N", bypass_header_checks=>"N", virus_quarantine_to=>"virus-quarantine", spam_quarantine_to=>"", banned_quarantine_to=>"banned-quarantine", unchecked_quarantine_to=>-, bad_header_quarantine_to=>"", clean_quarantine_to=>-, archive_quarantine_to=>-, spam_tag_level=>-, spam_tag2_level=>-, spam_tag3_level=>-, 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_admin=>-, bad_header_admin=>-, spam_admin=>-, spam_subject_tag=>-, spam_subject_tag2=>-, spam_subject_tag3=>-, message_size_limit=>-, banned_rulenames=>-, disclaimer_options=>-, forward_method=>-, sa_userconf=>-, sa_username=>-, id=>"1", local=>-)
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(message_size_limit) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [message_size_limit] => undef, "info@vortex.com.au" does not match
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250 2.1.5 Recipient <info@vortex.com.au> OK
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, smtp response sent
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 6: was busy, 14.4 ms, total idle 0.001 s, busy 0.022 s
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 5: was idle, 0.0 ms, total idle 0.001 s, busy 0.022 s
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP< DATA\r\n
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline switch_to_my_time(rx SMTP DATA) - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.856 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer switch_to_my_time(rx SMTP DATA): timer 288, was 480, deadline in 480.0 s
Apr 16 21:40:56.857 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP [127.0.0.1]:10024 /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w: <markslatter676@gmail.com> -> <info@vortex.com.au> SIZE=3699 Received: from mx.xxxx.com.au ([127.0.0.1]) by mx.xxxx.com.au (mx.xxxx.com.au [127.0.0.1]) (amavis, port 10024) with ESMTP for <info@vortex.com.au>; Wed, 16 Apr 2025 21:40:56 +1000 (AEST)
Apr 16 21:40:56.857 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 354 End data with <CR><LF>.<CR><LF>
Apr 16 21:40:56.857 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, smtp response sent
Apr 16 21:40:56.857 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, receiving data
Apr 16 21:40:56.880 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp copy: read 3708 bytes into buffer, new size: 3708
Apr 16 21:40:56.880 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp copy: 6 bytes still buffered at end
Apr 16 21:40:56.881 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline switch_to_my_time(rx data-end) - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.881 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer switch_to_my_time(rx data-end): timer 288, was 480, deadline in 480.0 s
Apr 16 21:40:56.881 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP< .<CR><LF>
Apr 16 21:40:56.881 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline get_body_digest - deadline in 480.0 s, set to 30.000 s
Apr 16 21:40:56.881 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline digest_pre - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.881 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer digest_pre: timer 288, was 288, deadline in 480.0 s
Apr 16 21:40:56.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) DNS resolver created, UDP payload size 1220, NS: 127.0.0.53
Apr 16 21:40:56.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_body_digest: reading header section from memory
Apr 16 21:40:56.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_body_digest: feeding header section to DKIM verifier
Apr 16 21:40:56.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_body_digest: sending h/b separator to DKIM
Apr 16 21:40:56.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline digest_hdr - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer digest_hdr: timer 288, was 288, deadline in 480.0 s
Apr 16 21:40:56.883 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_body_digest: reading mail body from memory, 0 DKIM signatures
Apr 16 21:40:56.883 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline digest_body - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.883 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer digest_body: timer 288, was 288, deadline in 480.0 s
Apr 16 21:40:56.883 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_body_digest: message size 3699, header+sep 748, body 2951
Apr 16 21:40:56.883 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) body type (8bit-MIMEtransport): unlabeled, good (h=0, b=0)
Apr 16 21:40:56.883 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) body hash: 68fcb53932ed6a41a38c749ebb806ebc
Apr 16 21:40:56.884 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ip_from_received: 162.248.102.44
Apr 16 21:40:56.885 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ip_from_received: 209.209.40.232
Apr 16 21:40:56.885 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_ip_acl (public_nets) arr.obj: key="127.0.0.1" matches "!127.0.0.0/8", result=0
Apr 16 21:40:56.885 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_ip_acl (public_nets) arr.obj: key="162.248.102.44" matches "::ffff:0:0/96", result=1
Apr 16 21:40:56.885 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_ip_acl (public_nets) arr.obj: key="209.209.40.232" matches "::ffff:0:0/96", result=1
Apr 16 21:40:56.885 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) trace: ESMTP://[127.0.0.1]:41022 < ESMTPS://[162.248.102.44]:40308 < ESMTPSA://209.209.40.232
Apr 16 21:40:56.885 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Original mail size: 3699; quota set to: 1849500 bytes (fmin=5, fmax=500, qmin=102400, qmax=524288000)
Apr 16 21:40:56.886 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql begin, nontransaction
Apr 16 21:40:56.886 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql: preparing and executing (2 args): SELECT id FROM maddr WHERE partition_tag=? AND email=?
Apr 16 21:40:56.892 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql begin, nontransaction
Apr 16 21:40:56.892 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql: preparing and executing (3 args): INSERT INTO maddr (partition_tag, email, domain) VALUES (?,?,?)
Apr 16 21:40:56.905 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql begin, nontransaction
Apr 16 21:40:56.907 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql: executing clause (2 args): SELECT id FROM maddr WHERE partition_tag=? AND email=?
Apr 16 21:40:56.907 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) find_or_save_addr: record inserted, id=27209, markslatter676@gmail.com
Apr 16 21:40:56.907 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) save_info_preliminary 2ywlAR6_I1ln, sender id: 27209, markslatter676@gmail.com, new
Apr 16 21:40:56.907 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql begin, nontransaction
Apr 16 21:40:56.907 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql: executing clause (2 args): SELECT id FROM maddr WHERE partition_tag=? AND email=?
Apr 16 21:40:56.908 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) orcpt_encode rfc822, info@vortex.com.au, smtputf8
Apr 16 21:40:56.908 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) save_info_preliminary 2ywlAR6_I1ln, recip id: 18352, info@vortex.com.au (ORCPT rfc822;info@vortex.com.au), exists
Apr 16 21:40:56.908 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql begin transaction
Apr 16 21:40:56.908 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-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 (?,?,?,?,?,?,?,?,?,?,?)
Apr 16 21:40:56.914 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql commit
Apr 16 21:40:56.916 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Checking: 2ywlAR6_I1ln [162.248.102.44] <markslatter676@gmail.com> -> <info@vortex.com.au>
Apr 16 21:40:56.916 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) 2822.From: <markslatter676@gmail.com>
Apr 16 21:40:56.916 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(local) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:40:56.916 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="1"
Apr 16 21:40:56.916 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [local_domains] => true,  "info@vortex.com.au" matches, result="1", matching_key="(constant:1)"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(bypass_virus_checks) rec=0, "info@vortex.com.au" result: "0"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [bypass_virus_checks] => false, "info@vortex.com.au" matches, result="0", matching_key="/cached/"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(bypass_banned_checks) rec=0, "info@vortex.com.au" result: "0"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [bypass_banned_checks] => false, "info@vortex.com.au" matches, result="0", matching_key="/cached/"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(bypass_spam_checks) rec=0, "info@vortex.com.au" result: "0"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [bypass_spam_checks] => false, "info@vortex.com.au" matches, result="0", matching_key="/cached/"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(id) rec=0, "info@vortex.com.au" result: "1"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [users.id], 1 matches for "info@vortex.com.au", results: "/cached/"=>"1"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(policy_id) rec=0, "info@vortex.com.au" result: "1"
Apr 16 21:40:56.917 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [users.policy_id] => true,  "info@vortex.com.au" matches, result="1", matching_key="/cached/"
Apr 16 21:40:56.918 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Extracting mime components from a string
Apr 16 21:40:56.919 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Issued a new file name: p001
Apr 16 21:40:56.921 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Charging 2687 bytes to remaining quota 1849500 (out of 1849500, (0%)) - by mime_decode
Apr 16 21:40:56.921 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) p001 1 Content-Type: text/html, QP, size: 2687, SHA1 digest: 4b864bf5c1c853f6536cc6b1d39d8f3a425007f1
Apr 16 21:40:56.922 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline mime_decode - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.922 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer mime_decode: timer 288, was 288, deadline in 480.0 s
Apr 16 21:40:56.922 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline mime_decode-1 - deadline in 480.0 s, set to 288.000 s
Apr 16 21:40:56.922 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer mime_decode-1: timer 288, was 288, deadline in 480.0 s
Apr 16 21:40:56.922 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) decode_parts: level=1, #parts=1 : p001
Apr 16 21:40:56.922 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) running file(1) on 1 files, arglist size 18
Apr 16 21:40:56.925 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) run_command: [98370] /usr/bin/file p001 </dev/null 2>&1
Apr 16 21:40:56.978 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) result line from file(1): p001: HTML document, ASCII text\n
Apr 16 21:40:56.979 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_re("HTML document, ASCII text") matches key "(?^i:\\btext\\b)", result="asc"
Apr 16 21:40:56.979 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [map_full_type_to_short_type] => true,  "HTML document, ASCII text" matches, result="asc", matching_key="(?^i:\\btext\\b)"
Apr 16 21:40:56.979 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) File-type of p001: HTML document, ASCII text; (asc)
Apr 16 21:40:56.979 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) decompose_part: p001 - atomic
Apr 16 21:40:56.980 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline parts_decode - deadline in 479.9 s, set to 288.000 s
Apr 16 21:40:56.980 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer parts_decode: timer 288, was 288, deadline in 479.9 s
Apr 16 21:40:56.980 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(bypass_header_checks) rec=0, "info@vortex.com.au" result: "0"
Apr 16 21:40:56.980 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [bypass_header_checks] => false, "info@vortex.com.au" matches, result="0", matching_key="/cached/"
Apr 16 21:40:56.980 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) check_header: 0, OK
Apr 16 21:40:56.980 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(bypass_header_checks) rec=0, "info@vortex.com.au" result: "0"
Apr 16 21:40:56.981 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [bypass_header_checks] => false, "info@vortex.com.au" matches, result="0", matching_key="/cached/"
Apr 16 21:40:56.981 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Checking for banned types and filenames
Apr 16 21:40:56.981 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(banned_rulenames) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:40:56.981 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="DEFAULT"
Apr 16 21:40:56.981 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [banned_filename], 1 matches for "info@vortex.com.au", results: "(constant:DEFAULT)"=>"DEFAULT"
Apr 16 21:40:56.982 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) collect banned table[0]: info@vortex.com.au, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x63cc07187188)
Apr 16 21:40:56.982 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) starting banned checks - traversing message structure tree
Apr 16 21:40:56.982 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) check_for_banned (p001) text/html,.asc
Apr 16 21:40:56.982 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) doing banned check for info@vortex.com.au on text/html,.asc
Apr 16 21:40:56.982 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_re(["text/html",".asc"]), no matches
Apr 16 21:40:56.983 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [check_bann:info@vortex.com.au] => undef, ["text/html",".asc"] does not match
Apr 16 21:40:56.983 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_re("P=p001\tL=1\tM=text/html\tT=asc"), no matches
Apr 16 21:40:56.983 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [banned_namepath_re] => undef, "P=p001\tL=1\tM=text/html\tT=asc" does not match
Apr 16 21:40:56.983 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) p.path info@vortex.com.au: "P=p001,L=1,M=text/html,T=asc"
Apr 16 21:40:56.983 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) banned check: any=0, all=N (1)
Apr 16 21:40:56.983 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_re("MAIL"), no matches
Apr 16 21:40:56.983 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [keep_decoded_original] => undef, "MAIL" does not match
Apr 16 21:40:56.984 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Calling virus scanners, 1 files to scan in /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w/parts
Apr 16 21:40:56.984 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) invoking av-scanner clamav-clamscan
Apr 16 21:40:56.984 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) run_av (clamav-clamscan): query template(0,0): --stdout --disable-summary -r --tempdir=/var/lib/amavis/tmp {}
Apr 16 21:40:56.984 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline run_av_pre - deadline in 479.9 s, set to 288.000 s
Apr 16 21:40:56.984 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer run_av_pre: timer 288, was 288, deadline in 479.9 s
Apr 16 21:40:56.984 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline run_av_scan - deadline in 479.9 s, set to 288.000 s
Apr 16 21:40:56.984 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer run_av_scan: timer 288, was 288, deadline in 479.9 s
Apr 16 21:40:56.984 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) run_av Using (clamav-clamscan): /usr/bin/clamscan --stdout --disable-summary -r --tempdir=/var/lib/amavis/tmp /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w/parts
Apr 16 21:40:56.989 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) run_command: [98371] /usr/bin/clamscan --stdout --disable-summary -r --tempdir=/var/lib/amavis/tmp /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w/parts </dev/null 2>&1
Apr 16 21:41:21.275 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) collect_results from [98371] (clamav-clamscan), 416 bytes, (limit 204800)
Apr 16 21:41:21.457 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline run_av_4 - deadline in 455.4 s, set to 274.000 s
Apr 16 21:41:21.461 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer run_av_4: timer 274, was 264, deadline in 455.4 s
Apr 16 21:41:21.490 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) run_av: /usr/bin/clamscan exit 0, WARNING: Ignoring deprecated option --disable-summary\n/var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w/parts/p001: OK\n\n----------- SCAN SUMMARY -----------\nKnown viruses: 8706304\nEngine version: 1.0.8\nScanned directories: 1\nScanned files: 1\nInfected files: 0\nData scanned: 0.00 MB\nData read: 0.00 MB (ratio 0.00:1)\nTime: 24.109 sec (0 m 24 s)\nStart Date: 2025:04:16 21:40:57\nEnd Date:   2025:04:16 21:41:21
Apr 16 21:41:21.511 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) run_av (clamav-clamscan): CLEAN
Apr 16 21:41:21.518 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) run_av (clamav-clamscan) result: clean
Apr 16 21:41:21.794 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) wbl: checking sender <markslatter676@gmail.com>
Apr 16 21:41:21.810 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) wbl: (SQL) recip <info@vortex.com.au>, 1 matches
Apr 16 21:41:22.006 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="1"
Apr 16 21:41:22.041 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [local_domains] => true,  "markslatter676@gmail.com" matches, result="1", matching_key="(constant:1)"
Apr 16 21:41:22.136 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) query_keys: markslatter676@gmail.com, markslatter676, @gmail.com, @.gmail.com, @.com, @.
Apr 16 21:41:22.190 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql sel_wblist "markslatter676@gmail.com", query args: "1", [markslatter676@gmail.com,-3], [markslatter676,-3], [@gmail.com,-3], [@.gmail.com,-3], [@.com,-3], [@.,-3]
Apr 16 21:41:22.192 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-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
Apr 16 21:41:22.210 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql begin, nontransaction
Apr 16 21:41:22.289 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-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
Apr 16 21:41:22.417 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql, "markslatter676@gmail.com" no match
Apr 16 21:41:22.421 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(wb), "markslatter676@gmail.com" no matching records
Apr 16 21:41:22.426 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup => undef, "markslatter676@gmail.com" does not match
Apr 16 21:41:22.439 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) wbl: (SQL) recip <info@vortex.com.au>, rid=1, got: ""
Apr 16 21:41:22.453 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [blacklist_recip<info@vortex.com.au>] => undef, "info@vortex.com.au" does not match
Apr 16 21:41:22.467 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [blacklist_sender<markslatter676@gmail.com>,blacklist_sender] => undef, "markslatter676@gmail.com" does not match
Apr 16 21:41:22.473 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [whitelist_recip<info@vortex.com.au>] => undef, "info@vortex.com.au" does not match
Apr 16 21:41:22.494 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_acl(markslatter676@gmail.com), no match
Apr 16 21:41:22.495 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [whitelist_sender<markslatter676@gmail.com>,whitelist_sender] => undef, "markslatter676@gmail.com" does not match
Apr 16 21:41:22.531 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) query_keys: info@vortex.com.au, info@, vortex.com.au, .vortex.com.au, .com.au, .au, .
Apr 16 21:41:22.539 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_hash(info@vortex.com.au) matches keys: "."=>ARRAY(0x63cc06022020)
Apr 16 21:41:22.623 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [score_recip<info@vortex.com.au>,score_sender], 1 matches for "info@vortex.com.au", results: "."=>[Amavis::Lookup::RE=ARRAY(0x63cc07c4a870),{slashdot@slashdot.org=>"-3",ietf-123-owner@loki.ietf.org=>"-3",noreply@freshmeat.net=>"-3",cvs-commits-list-admin@gnome.org=>"-3",.example.net=>"1",sender@example.net=>"3",sendmail-announce-request@lists.sendmail.org=>"-3",owner-postfix-announce@postfix.org=>"-3",returns.groups.yahoo.com=>"-3",ntbugtraq@listserv.ntbugtraq.com=>"-3",mailman-announce-admin@python.org=>"-3",securityfocus.com=>"-3",owner-postfix-users@postfix.org=>"-3",amavis-user-bounces@lists.sourceforge.net=>"-3",owner-textbreakingnews@cnnimail12.cnn.com=>"-5",owner-sendmail-announce@lists.sendmail.org=>"-3",yahoo-dev-null@yahoo-inc.com=>"-3",clp-request@comp.nus.edu.sg=>"-3",ca+envelope@sendmail.org=>"-3",spamassassin.apache.org=>"-3",owner-technews@postel.acm.org=>"-3",owner-alert@iss.net=>"-3",clusternews@linuxnetworx.com=>"-3",notification-return@lists.sophos.com=>"-3",donotreply@sendmail.org=>"-3",cert-advisory@us-cert.gov=>"-3",rt-users-admin@lists.fsck.com=>"-3",amavis-user-admin@lists.sourceforge.net=>"-3",emailnews@genomeweb.com=>"-5",nobody@cert.org=>"-3",security-alerts@linuxsecurity.com=>"-3",surveys-errors@lists.nua.ie=>"-3",lvs-users-admin@linuxvirtualserver.org=>"-3"}]
Apr 16 21:41:22.683 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_re("markslatter676@gmail.com"), no matches
Apr 16 21:41:22.687 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) query_keys: markslatter676@gmail.com, markslatter676@, gmail.com, .gmail.com, .com, .
Apr 16 21:41:22.688 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_hash(markslatter676@gmail.com), no matches
Apr 16 21:41:22.689 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [score_sender<markslatter676@gmail.com>] => undef, "markslatter676@gmail.com" does not match
Apr 16 21:41:22.710 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) SpamControl: calling spam scanner SpamAssassin
Apr 16 21:41:22.795 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline spam_scan_sa_pre - deadline in 454.1 s, set to 451.000 s
Apr 16 21:41:22.795 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer spam_scan_sa_pre: timer 451, was 273, deadline in 454.1 s
Apr 16 21:41:22.853 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(sa_userconf) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:22.853 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [sa_userconf] => undef, "info@vortex.com.au" does not match
Apr 16 21:41:22.862 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(sa_username) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:22.862 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [sa_username] => undef, "info@vortex.com.au" does not match
Apr 16 21:41:22.889 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) SA user config: "", username: "amavis", 0, (0)info@vortex.com.au
Apr 16 21:41:22.896 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) calling SA parse (0), SA vers 4.0.0, 4.000000, data as STRING_REF, recips_ind [0], user: "amavis"
Apr 16 21:41:23.051 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline SA check - deadline in 453.8 s, set to 449.000 s
Apr 16 21:41:23.070 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) mimepart digest: 4b864bf5c1c853f6536cc6b1d39d8f3a425007f1:text/html
Apr 16 21:41:23.610 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) CALLING SA check (0)
Apr 16 21:41:33.616 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) _WARN: check: dns_block_rule RCVD_IN_ZEN_BLOCKED_OPENDNS hit, creating /var/lib/amavis/.spamassassin/dnsblock_zen.spamhaus.org (This means DNSBL blocked you due to too many queries. Set all affected rules score to 0, or use "dns_query_restriction deny zen.spamhaus.org" to disable queries)
Apr 16 21:41:33.680 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) DONE SA check (0)
Apr 16 21:41:33.717 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline spam_scan_sa - deadline in 443.2 s, set to 266.000 s
Apr 16 21:41:33.717 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer spam_scan_sa: timer 266, was 441, deadline in 443.2 s
Apr 16 21:41:33.729 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) spam_scan: score=3.878 autolearn=no autolearn_force=no tests=[BAYES_60=1.5,DKIM_ADSP_CUSTOM_MED=0.001,DMARC_NONE=0.898,FORGED_GMAIL_RCVD=1,FREEMAIL_ENVFROM_END_DIGIT=0.25,FREEMAIL_FROM=0.001,FREEMAIL_REPLYTO_END_DIGIT=0.25,HTML_MESSAGE=0.001,MIME_HTML_ONLY=0.1,NML_ADSP_CUSTOM_MED=0.9,RCVD_IN_VALIDITY_CERTIFIED=-3,RCVD_IN_VALIDITY_RPBL=1.31,RCVD_IN_VALIDITY_SAFE=-2,RCVD_IN_ZEN_BLOCKED_OPENDNS=0.001,SPF_HELO_NONE=0.001,SPF_SOFTFAIL=0.665,SPOOFED_FREEMAIL=1,SPOOF_GMAIL_MID=1] recips=0
Apr 16 21:41:33.741 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline spam_scan - deadline in 443.1 s, set to 266.000 s
Apr 16 21:41:33.741 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer spam_scan: timer 266, was 266, deadline in 443.1 s
Apr 16 21:41:33.763 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(spam_tag_level) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:33.764 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="2"
Apr 16 21:41:33.764 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [spam_tag_level] => true,  "info@vortex.com.au" matches, result="2", matching_key="(constant:2)"
Apr 16 21:41:33.764 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(spam_tag2_level) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:33.764 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="6.2"
Apr 16 21:41:33.764 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [spam_tag2_level] => true,  "info@vortex.com.au" matches, result="6.2", matching_key="(constant:6.2)"
Apr 16 21:41:33.764 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(spam_tag3_level) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:33.764 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [spam_tag3_level] => undef, "info@vortex.com.au" does not match
Apr 16 21:41:33.765 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(spam_kill_level) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:33.765 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="6.9"
Apr 16 21:41:33.765 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [spam_kill_level] => true,  "info@vortex.com.au" matches, result="6.9", matching_key="(constant:6.9)"
Apr 16 21:41:33.774 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(message_size_limit) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:33.774 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [message_size_limit] => undef, "info@vortex.com.au" does not match
Apr 16 21:41:33.776 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) final_destiny (ccat=0) is PASS, recip info@vortex.com.au
Apr 16 21:41:33.781 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) final_destiny PASS, recip info@vortex.com.au
Apr 16 21:41:33.793 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) do_notify_and_quar: ccat=CleanTag (1,1) ("1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(), qar_mth=
Apr 16 21:41:33.797 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) do_notify_and_quarantine: not quarantining, q_method off
Apr 16 21:41:33.800 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) skip admin notification, no administrators
Apr 16 21:41:33.801 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) do_notify_and_quarantine - done
Apr 16 21:41:33.810 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(forward_method) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:33.829 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (opaque) matches, result="smtp:[127.0.0.1]:10025"
Apr 16 21:41:33.829 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [forward_method] => true,  "info@vortex.com.au" matches, result="smtp:[127.0.0.1]:10025", matching_key="(opaque:smtp:[127.0.0.1]:10025)"

**Vortex** · 2025-04-16 19:54:24

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Vortex wrote:

Thank you. I need to do it in 2 parts due to exceeding post length...

Part 2.

Apr 16 21:41:33.833 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) delivery method is 1, recips: info@vortex.com.au
Apr 16 21:41:33.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(spam_tag_level) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:33.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="2"
Apr 16 21:41:33.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [spam_tag_level] => true,  "info@vortex.com.au" matches, result="2", matching_key="(constant:2)"
Apr 16 21:41:33.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(spam_tag2_level) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:33.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="6.2"
Apr 16 21:41:33.882 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [spam_tag2_level] => true,  "info@vortex.com.au" matches, result="6.2", matching_key="(constant:6.2)"
Apr 16 21:41:33.885 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup_sql_field(spam_subject_tag) rec=0, "info@vortex.com.au" result: undef
Apr 16 21:41:33.886 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [spam_subject_tag] => undef, "info@vortex.com.au" does not match
Apr 16 21:41:33.890 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) headers CLUSTERING: NEW CLUSTER <info@vortex.com.au>: score=3.878, tag=1, tag2=0, local=1, bl=, s=, mangle=, ccat_hdr=
Apr 16 21:41:33.894 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header encoded (all-ASCII): X-Virus-Scanned: Debian amavis at webmx
Apr 16 21:41:33.898 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header: X-Virus-Scanned: Debian amavis at webmx\n
Apr 16 21:41:33.899 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header encoded (all-ASCII): X-Spam-Flag: NO
Apr 16 21:41:33.899 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header: X-Spam-Flag: NO\n
Apr 16 21:41:33.899 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header encoded (all-ASCII): X-Spam-Score: 3.878
Apr 16 21:41:33.899 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header: X-Spam-Score: 3.878\n
Apr 16 21:41:33.899 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header encoded (all-ASCII): X-Spam-Level: ***
Apr 16 21:41:33.899 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header: X-Spam-Level: ***\n
Apr 16 21:41:33.900 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header encoded (all-ASCII): X-Spam-Status: No,\n score=3.878\n tagged_above=2\n required=6.2\n tests=[BAYES_60=1.5,\n DKIM_ADSP_CUSTOM_MED=0.001,\n DMARC_NONE=0.898,\n FORGED_GMAIL_RCVD=1,\n FREEMAIL_ENVFROM_END_DIGIT=0.25,\n FREEMAIL_FROM=0.001,\n FREEMAIL_REPLYTO_END_DIGIT=0.25,\n HTML_MESSAGE=0.001,\n MIME_HTML_ONLY=0.1,\n NML_ADSP_CUSTOM_MED=0.9,\n RCVD_IN_VALIDITY_CERTIFIED=-3,\n RCVD_IN_VALIDITY_RPBL=1.31,\n RCVD_IN_VALIDITY_SAFE=-2,\n RCVD_IN_ZEN_BLOCKED_OPENDNS=0.001,\n SPF_HELO_NONE=0.001,\n SPF_SOFTFAIL=0.665,\n SPOOFED_FREEMAIL=1,\n SPOOF_GMAIL_MID=1]\n autolearn=no autolearn_force=no
Apr 16 21:41:33.913 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header: X-Spam-Status: No, score=3.878 tagged_above=2 required=6.2\n tests=[BAYES_60=1.5, DKIM_ADSP_CUSTOM_MED=0.001, DMARC_NONE=0.898,\n FORGED_GMAIL_RCVD=1, FREEMAIL_ENVFROM_END_DIGIT=0.25, FREEMAIL_FROM=0.001,\n FREEMAIL_REPLYTO_END_DIGIT=0.25, HTML_MESSAGE=0.001, MIME_HTML_ONLY=0.1,\n NML_ADSP_CUSTOM_MED=0.9, RCVD_IN_VALIDITY_CERTIFIED=-3,\n RCVD_IN_VALIDITY_RPBL=1.31, RCVD_IN_VALIDITY_SAFE=-2,\n RCVD_IN_ZEN_BLOCKED_OPENDNS=0.001, SPF_HELO_NONE=0.001, SPF_SOFTFAIL=0.665,\n SPOOFED_FREEMAIL=1, SPOOF_GMAIL_MID=1] autolearn=no autolearn_force=no\n
Apr 16 21:41:33.914 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) fwd: scanner provided a header field X-Spam-Checker-Version, inhibited by %allowed_added_header_fields
Apr 16 21:41:33.914 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) fwd: scanner provided a header field X-Spam-Level, but we preferred our own
Apr 16 21:41:33.914 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) fwd: scanner provided a header field X-Spam-Status, but we preferred our own
Apr 16 21:41:33.965 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header encoded (all-ASCII): Received: from mx.xxxx.com.au ([127.0.0.1])\n by mx.xxxx.com.au (mx.xxxx.com.au [127.0.0.1]) (amavis, port 10024)\n with ESMTP\n id 2ywlAR6_I1ln\n for <info@vortex.com.au>;\n Wed, 16 Apr 2025 21:40:56 +1000 (AEST)
Apr 16 21:41:33.965 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) header: Received: from mx.xxxx.com.au ([127.0.0.1])\n by mx.xxxx.com.au (mx.xxxx.com.au [127.0.0.1]) (amavis, port 10024)\n with ESMTP id 2ywlAR6_I1ln for <info@vortex.com.au>;\n Wed, 16 Apr 2025 21:40:56 +1000 (AEST)\n
Apr 16 21:41:33.966 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) headers CLUSTERING: done all 1 recips in one go
Apr 16 21:41:33.969 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) spam-tag, <markslatter676@gmail.com> -> <info@vortex.com.au>, No, score=3.878 tagged_above=2 required=6.2 tests=[BAYES_60=1.5, DKIM_ADSP_CUSTOM_MED=0.001, DMARC_NONE=0.898, FORGED_GMAIL_RCVD=1, FREEMAIL_ENVFROM_END_DIGIT=0.25, FREEMAIL_FROM=0.001, FREEMAIL_REPLYTO_END_DIGIT=0.25, HTML_MESSAGE=0.001, MIME_HTML_ONLY=0.1, NML_ADSP_CUSTOM_MED=0.9, RCVD_IN_VALIDITY_CERTIFIED=-3, RCVD_IN_VALIDITY_RPBL=1.31, RCVD_IN_VALIDITY_SAFE=-2, RCVD_IN_ZEN_BLOCKED_OPENDNS=0.001, SPF_HELO_NONE=0.001, SPF_SOFTFAIL=0.665, SPOOFED_FREEMAIL=1, SPOOF_GMAIL_MID=1] autolearn=no autolearn_force=no
Apr 16 21:41:33.997 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) dkim: not signing mail which is not originating from our site
Apr 16 21:41:34.039 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) about to connect to smtp:[127.0.0.1]:10025, 2ywlAR6_I1ln FWD from <markslatter676@gmail.com> -> <info@vortex.com.au>
Apr 16 21:41:34.047 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline fwd_init - deadline in 442.8 s, set to 443.000 s
Apr 16 21:41:34.148 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp session: setting up a new session
Apr 16 21:41:34.148 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) establish_or_refresh, state: down
Apr 16 21:41:34.210 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) new socket using IO::Socket::IP to [127.0.0.1]:10025, timeout 35
Apr 16 21:41:34.212 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) verifycn_name: 127.0.0.1
Apr 16 21:41:34.213 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) connected to [127.0.0.1]:10025 successfully
Apr 16 21:41:34.227 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: needline=1, flush=0, wr=0, timeout=35
Apr 16 21:41:34.240 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: receiving
Apr 16 21:41:34.242 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop read 34 chars< 220 mx.xxxx.com.au ESMTP Postfix\r\n
Apr 16 21:41:34.246 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp greeting: 220 mx.xxxx.com.au ESMTP Postfix, dt: 38.0 ms
Apr 16 21:41:34.246 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp cmd> EHLO mx.xxxx.com.au
Apr 16 21:41:34.252 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: needline=0, flush=1, wr=1, timeout=300
Apr 16 21:41:34.252 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: sending 21 chars
Apr 16 21:41:34.252 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop sent 21> EHLO mx.xxxx.com.au\r\n
Apr 16 21:41:34.252 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: needline=1, flush=0, wr=0, timeout=300
Apr 16 21:41:34.252 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: receiving
Apr 16 21:41:34.252 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop read 113 chars< 250-mx.xxxx.com.au\r\n250-PIPELINING\r\n250-SIZE 15728640\r\n250-ETRN\r\n250-ENHANCEDSTATUSCODES\r\n250-8BITMIME\r\n250 DSN\r\n
Apr 16 21:41:34.253 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp resp to EHLO: 250 mx.xxxx.com.au\nPIPELINING\nSIZE 15728640\nETRN\nENHANCEDSTATUSCODES\n8BITMIME\nDSN
Apr 16 21:41:34.253 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) tls active=0, capable=, sec_level=0
Apr 16 21:41:34.263 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Remote host presents itself as: mx.xxxx.com.au, handles DSN, PIPELINING, 8BITMIME
Apr 16 21:41:34.274 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) AUTH not needed, user='', MTA offers ''
Apr 16 21:41:34.279 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp cmd> MAIL FROM:<markslatter676@gmail.com> BODY=7BIT
Apr 16 21:41:34.285 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) orcpt_encode rfc822, info@vortex.com.au, encode_for_smtp
Apr 16 21:41:34.287 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp cmd> RCPT TO:<info@vortex.com.au> ORCPT=rfc822;info@vortex.com.au
Apr 16 21:41:34.290 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp cmd> DATA
Apr 16 21:41:34.290 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: needline=0, flush=1, wr=1, timeout=120
Apr 16 21:41:34.290 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: sending 116 chars
Apr 16 21:41:34.290 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop sent 116> MAIL FROM:<markslatter676@gmail.com> BODY=7BIT\r\nRCPT TO:<info@vortex.com.au> ORCPT=rfc822;info@vortex.com.au\r\nDATA\r\n
Apr 16 21:41:34.292 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: needline=1, flush=0, wr=0, timeout=300
Apr 16 21:41:34.337 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: receiving
Apr 16 21:41:34.338 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop read 65 chars< 250 2.1.0 Ok\r\n250 2.1.5 Ok\r\n354 End data with <CR><LF>.<CR><LF>\r\n
Apr 16 21:41:34.339 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp resp to MAIL (pip): 250 2.1.0 Ok
Apr 16 21:41:34.350 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp resp to RCPT (pip) (<info@vortex.com.au>): 250 2.1.5 Ok
Apr 16 21:41:34.353 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp resp to DATA: 354 End data with <CR><LF>.<CR><LF>
Apr 16 21:41:34.358 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) write_header: 1, Amavis::Out::SMTP::Protocol=HASH(0x63cc0b458c90)
Apr 16 21:41:34.364 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp connection_cache disabled, sending QUIT
Apr 16 21:41:34.364 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp cmd> QUIT
Apr 16 21:41:34.364 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: needline=0, flush=1, wr=1, timeout=442.684
Apr 16 21:41:34.364 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: sending 4563 chars
Apr 16 21:41:34.364 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop sent 4563> X-Virus-Scanned: Debian amavis at webmx\r\nX-Spam-Flag: NO\r\nX-Spam-Score: 3.878\r\nX-Spam-Level: ***\r\nX-Spam-Status: No, score=3.878 tagged_above=2 required=6.2\r\n tests=[BAYES_60=1.5, DKIM_ADSP_CUSTOM_MED [...]
Apr 16 21:41:34.367 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: needline=1, flush=0, wr=0, timeout=442.684
Apr 16 21:41:34.368 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop: receiving
Apr 16 21:41:34.368 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rw_loop read 56 chars< 250 2.0.0 Ok: queued as 4ZczdB2MsBz9d7T\r\n221 2.0.0 Bye\r\n
Apr 16 21:41:34.369 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) smtp resp to data-dot (<info@vortex.com.au>): 250 2.0.0 Ok: queued as 4ZczdB2MsBz9d7T, dt: 4.4 ms
Apr 16 21:41:34.370 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Amavis::Out::SMTP::Session close, disconnecting
Apr 16 21:41:34.375 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline fwd-end-chkpnt - deadline in 442.5 s, set to 266.000 s
Apr 16 21:41:34.375 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer fwd-end-chkpnt: timer 266, was 0, deadline in 442.5 s
Apr 16 21:41:34.380 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) 2ywlAR6_I1ln FWD from <markslatter676@gmail.com> -> <info@vortex.com.au>, BODY=7BIT 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4ZczdB2MsBz9d7T
Apr 16 21:41:34.387 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline forwarding - deadline in 442.5 s, set to 266.000 s
Apr 16 21:41:34.387 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer forwarding: timer 266, was 266, deadline in 442.5 s
Apr 16 21:41:34.399 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) DSN: sender NOT credible, SA: 3.878, <markslatter676@gmail.com>
Apr 16 21:41:34.402 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup: (scalar) matches, result="10"
Apr 16 21:41:34.402 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) lookup [spam_dsn_cutoff_level_bysender] => true,  "markslatter676@gmail.com" matches, result="10", matching_key="(constant:10)"
Apr 16 21:41:34.410 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) dsn: from MTA 250 NonBlocking:CleanTag <markslatter676@gmail.com> -> <info@vortex.com.au>: on_succ=0, on_dly=1, on_fail=1, never=0, warn_sender=, DSN_passed_on=1, destiny=1, mta_resp: "250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4ZczdB2MsBz9d7T"
Apr 16 21:41:34.410 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) DSN: SUCC from MTA 250 NonBlocking:CleanTag, no DSN requested: <markslatter676@gmail.com> -> <info@vortex.com.au>
Apr 16 21:41:34.414 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) delivery_status_notification: notif 0 bytes, suppressed: no
Apr 16 21:41:34.416 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) one_response_for_all, per_recip_capable: N, suppressed: N
Apr 16 21:41:34.419 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) one_response_for_all <markslatter676@gmail.com>: success, r=0,b=0,d=0, ndn_needed=0, '250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4ZczdB2MsBz9d7T'
Apr 16 21:41:34.419 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) notif=N, suppressed=0, ndn_needed=0, exit=0, 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4ZczdB2MsBz9d7T
Apr 16 21:41:34.420 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline delivery-notification - deadline in 442.5 s, set to 266.000 s
Apr 16 21:41:34.420 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer delivery-notification: timer 266, was 266, deadline in 442.5 s
Apr 16 21:41:34.427 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) status counters: InMsgsStatus{Relayed,RelayedUntagged,RelayedUntaggedInbound}
Apr 16 21:41:34.427 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline snmp-counters - deadline in 442.5 s, set to 266.000 s
Apr 16 21:41:34.427 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer snmp-counters: timer 266, was 266, deadline in 442.5 s
Apr 16 21:41:34.446 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) orcpt_encode rfc822, info@vortex.com.au, smtputf8
Apr 16 21:41:34.581 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) oldest_public_ip_addr_from_received: 209.209.40.232
Apr 16 21:41:34.603 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Passed CLEAN {RelayedInbound}, [162.248.102.44]:40308 [209.209.40.232] <markslatter676@gmail.com> -> <info@vortex.com.au>, Queue-ID: 4ZczcS41Rzz9dpX, Message-ID: <20250416041245.65147666729D06B0@gmail.com>, mail_id: 2ywlAR6_I1ln, Hits: 3.878, size: 3699, queued_as: 4ZczdB2MsBz9d7T, 37769 ms
Apr 16 21:41:34.606 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline main_log_entry - deadline in 442.3 s, set to 266.000 s
Apr 16 21:41:34.606 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer main_log_entry: timer 266, was 266, deadline in 442.3 s
Apr 16 21:41:34.623 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql begin transaction
Apr 16 21:41:34.635 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-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 (?,?,?,?,?,?,?,?,?,?,?,?)
Apr 16 21:41:34.649 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) save_info_final 2ywlAR6_I1ln, orig=N, chks=VSHB, cont.ty=C, q.type= , q.to=, dsn=N, score=3.878, Message-ID: <20250416041245.65147666729D06B0@gmail.com>, From: '"Mark Slatter" <markslatter676@gmail.com>', Subject: 'Let’s Redesign Your Website.'
Apr 16 21:41:34.649 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-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=?
Apr 16 21:41:34.662 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sql commit
Apr 16 21:41:34.665 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) TIMING-SA total 10545 ms - parse: 447 (4.2%), extract_message_metadata: 559 (5.3%), tests_pri_-10000: 280 (2.7%), get_uri_detail_list: 52 (0.5%), tests_pri_-2000: 164 (1.6%), tests_pri_-1000: 68 (0.6%), tests_pri_-950: 44 (0.4%), tests_pri_-900: 26 (0.3%), tests_pri_-100: 4033 (38.2%), check_spf: 725 (6.9%), poll_dns_idle: 103 (1.0%), check_razor2: 45 (0.4%), check_pyzor: 47 (0.4%), tests_pri_-90: 541 (5.1%), check_bayes: 491 (4.7%), b_tie_ro: 133 (1.3%), b_tokenize: 112 (1.1%), b_tok_get_all: 29 (0.3%), b_comp_prob: 34 (0.3%), b_tok_touch_all: 12 (0.1%), b_finish: 19 (0.2%), tests_pri_0: 2693 (25.5%), tests_pri_500: 13 (0.1%), get_report: 2.1 (0.0%)
Apr 16 21:41:34.681 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline check done - deadline in 442.2 s, set to 266.000 s
Apr 16 21:41:34.681 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer check done: timer 266, was 266, deadline in 442.2 s
Apr 16 21:41:34.683 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sending SMTP response: "250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4ZczdB2MsBz9d7T"
Apr 16 21:41:34.690 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4ZczdB2MsBz9d7T
Apr 16 21:41:34.692 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, smtp response sent
Apr 16 21:41:34.703 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) TempDir::strip: /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w
Apr 16 21:41:34.705 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rmdir_recursively: /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w/parts, excl=1
Apr 16 21:41:34.758 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) size: 3699, TIMING [total 37921 ms] - sql-prepare: 1.5 (0%)0, SMTP greeting: 0.9 (0%)0, SMTP EHLO: 1.5 (0%)0, SMTP pre-MAIL: 2.2 (0%)0, mkdir tempdir: 0.5 (0%)0, create email.txt: 0.3 (0%)0, SMTP MAIL: 0.8 (0%)0, sql-connect: 2.6 (0%)0, lookup_sql: 12 (0%)0, SMTP pre-DATA-flush: 0.7 (0%)0, SMTP DATA: 24 (0%)0, check_init: 0.1 (0%)0, digest_hdr: 1.4 (0%)0, digest_body_dkim: 0.7 (0%)0, collect_info: 2.3 (0%)0, gen_mail_id: 30 (0%)0, mkdir parts: 1.9 (0%)0, mime_decode: 3.9 (0%)0, get-file-type1: 58 (0%)0, parts_decode: 0.2 (0%)0, check_header: 1.1 (0%)0, AV-scan-1: 24564 (65%)65, lookup_sql: 875 (2%)67, spam-wb-list: 271 (1%)68, SA msg read: 127 (0%)69, SA parse: 791 (2%)71, SA check: 10071 (27%)97, decide_mail_destiny: 101 (0%)97, notif-quar: 17 (0%)97, fwd-connect: 471 (1%)99, fwd-mail-pip: 70 (0%)99, fwd-rcpt-pip: 10 (0%)99, fwd-data-chkpnt: 1.0 (0%)99, write-header: 11 (0%)99, fwd-data-contents: 2.1 (0%)99, fwd-end-chkpnt: 17 (0%)99, prepare-dsn: 38 (0%)99, report: 101 (0%)99, main_log_entry: 85 (0%)100, sql-update: 59 (0%)100, SMTP pre-response: 18 (0%)100, SMTP response: 10 (0%)100, unlink-1-files: 15 (0%)100, rundown: 47 (0%)100
Apr 16 21:41:34.764 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 6: was busy, 37905.3 ms, total idle 0.001 s, busy 37.927 s
Apr 16 21:41:34.772 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, 5: was idle, 9.9 ms, total idle 0.011 s, busy 37.927 s
Apr 16 21:41:34.772 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP< QUIT\r\n
Apr 16 21:41:34.773 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) get_deadline switch_to_my_time(rx SMTP QUIT) - deadline in 480.0 s, set to 288.000 s
Apr 16 21:41:34.773 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) prolong_timer switch_to_my_time(rx SMTP QUIT): timer 288, was 480, deadline in 480.0 s
Apr 16 21:41:34.776 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) ESMTP> 221 2.0.0 [127.0.0.1] amavis closing transmission channel
Apr 16 21:41:34.776 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) switch_to_client_time 480 s, smtp response sent
Apr 16 21:41:34.778 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) SMTP session over, timer stopped
Apr 16 21:41:34.786 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Requesting process rundown after 1 tasks (and 1 sessions)
Apr 16 21:41:34.789 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) TempDir::DESTROY called
Apr 16 21:41:34.789 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) TempDir removal: empty tempdir is being removed: /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w
Apr 16 21:41:34.789 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rmdir_recursively: /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w, excl=
Apr 16 21:41:34.790 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) rmdir_recursively: /var/lib/amavis/tmp/amavis-20250416T214056-97926-39zRjS4w/parts, excl=
Apr 16 21:41:34.913 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) extra modules loaded: Amavis/Lookup/Opaque.pm, Amavis/Out/SMTP/Protocol.pm, Amavis/Out/SMTP/Session.pm
Apr 16 21:41:35.077 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) exiting process_request
Apr 16 21:41:35.082 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) idle_proc, bye: was busy, 310.8 ms, total idle 0.011 s, busy 38.238 s
Apr 16 21:41:35.083 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) load: 100 %, total idle 0.011 s, busy 38.238 s
Apr 16 21:41:35.108 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sd_notify (no socket): STOPPING=1\nSTATUS=Server rundown, notifying child processes.
Apr 16 21:41:35.124 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Net::Server: 2025/04/16-21:41:35 Server closing!
Apr 16 21:41:35.126 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) sd_notify (no socket): STATUS=Child processes have been stopped.
Apr 16 21:41:35.223 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Amavis::Out::SQL::Log DESTROY called
Apr 16 21:41:35.224 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Amavis::Lookup::SQL DESTROY called
Apr 16 21:41:35.383 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Amavis::Out::SQL::Connection DESTROY called
Apr 16 21:41:36.210 mx.xxxx.com.au /usr/sbin/amavisd[97926]: (97926-01) Amavis::Lookup::SQL DESTROY called

**Vortex** · 2025-04-16 20:20:03

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Vortex wrote:

Thought I'd add this also

ubuntu@webmx:/$ sudo systemctl status amavis.service
● amavis.service - LSB: Starts amavisd-new mailfilter
     Loaded: loaded (/etc/init.d/amavis; enabled; preset: enabled)
     Active: active (exited) since Wed 2025-04-16 22:15:48 AEST; 7s ago
       Docs: man:systemd-sysv-generator(8)
    Process: 109964 ExecStart=/etc/init.d/amavis start (code=exited, status=0/SUCCESS)
        CPU: 8ms

Apr 16 22:15:48 webmx systemd[1]: Starting amavis.service - LSB: Starts amavisd-new mailfilter...
Apr 16 22:15:48 webmx systemd[1]: Started amavis.service - LSB: Starts amavisd-new mailfilter.

ubuntu@webmx:/$ sudo systemctl status mariadb.service
● mariadb.service - MariaDB 10.11.11 database server
     Loaded: loaded (/usr/lib/systemd/system/mariadb.service; enabled; preset: enabled)
    Drop-In: /etc/systemd/system/mariadb.service.d
             └─migrated-from-my.cnf-settings.conf, override.conf
     Active: active (running) since Wed 2025-04-16 22:18:53 AEST; 7s ago
       Docs: man:mariadbd(8)
             https://mariadb.com/kb/en/library/systemd/
    Process: 110754 ExecStartPre=/usr/bin/install -m 755 -o mysql -g root -d /var/run/mysqld (code=exited, status=0/SUCCESS)
    Process: 110756 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
    Process: 110759 ExecStartPre=/bin/sh -c [ ! -e /usr/bin/galera_recovery ] && VAR= ||   VAR=`/usr/bin/galera_recovery`; [ $? -eq 0 ]   && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (cod>
    Process: 110835 ExecStartPost=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
    Process: 110837 ExecStartPost=/etc/mysql/debian-start (code=exited, status=0/SUCCESS)
   Main PID: 110821 (mariadbd)
     Status: "Taking your SQL requests now..."
      Tasks: 14 (limit: 15141)
     Memory: 110.6M (peak: 113.6M)
        CPU: 530ms
     CGroup: /system.slice/mariadb.service
             └─110821 /usr/sbin/mariadbd

Apr 16 22:18:53 webmx mariadbd[110821]: 2025-04-16 22:18:53 0 [Warning] You need to use --log-bin to make --expire-logs-days or --binlog-expire-logs-seconds work.
Apr 16 22:18:53 webmx mariadbd[110821]: 2025-04-16 22:18:53 0 [Note] Server socket created on IP: '127.0.0.1'.
Apr 16 22:18:53 webmx mariadbd[110821]: 2025-04-16 22:18:53 0 [Note] InnoDB: Buffer pool(s) load completed at 250416 22:18:53
Apr 16 22:18:53 webmx mariadbd[110821]: 2025-04-16 22:18:53 0 [Note] /usr/sbin/mariadbd: ready for connections.
Apr 16 22:18:53 webmx mariadbd[110821]: Version: '10.11.11-MariaDB-0ubuntu0.24.04.2'  socket: '/run/mysqld/mysqld.sock'  port: 3306  Ubuntu 24.04
Apr 16 22:18:53 webmx systemd[1]: Started mariadb.service - MariaDB 10.11.11 database server.
Apr 16 22:18:53 webmx /etc/mysql/debian-start[110840]: Upgrading MariaDB tables if necessary.
Apr 16 22:18:53 webmx /etc/mysql/debian-start[110843]: /usr/bin/mariadb-upgrade: the '--basedir' option is always ignored
Apr 16 22:18:53 webmx /etc/mysql/debian-start[110851]: Checking for insecure root accounts.
Apr 16 22:18:53 webmx /etc/mysql/debian-start[110855]: Triggering myisam-recover for all MyISAM tables and aria-recover for all Aria tables

**ZhangHuangbin** · 2025-04-16 21:28:35

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 31,361

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Amavisd seems fine, you can go back to restart it with systemctl.

**Vortex** · 2025-04-17 03:59:41

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

ZhangHuangbin wrote:

Amavisd seems fine, you can go back to restart it with systemctl.

Ok, thank you. I still had errors, and I have done some further digging and discovered there was no directory "/var/lib/amavis/tmp", I have added that, and also the ownership at "/var/lib/dkim" was somehow corrupted to read "117:amavis" and I have fixed that to read "amavis:amavis". I now believe the Amavis/Postfix problem has been resolved. Thank you.

See below systemctl status amavis.service and mail is now being delivered.

 sudo systemctl status amavis.service
● amavis.service - LSB: Starts amavisd-new mailfilter
     Loaded: loaded (/etc/init.d/amavis; indirect; preset: enabled)
     Active: active (running) since Thu 2025-04-17 07:47:50 AEST; 12min ago
       Docs: man:systemd-sysv-generator(8)
    Process: 41879 ExecStart=/etc/init.d/amavis start (code=exited, status=0/SUCCESS)
      Tasks: 2 (limit: 2294)
     Memory: 227.1M (peak: 1.5G swap: 162.4M swap peak: 196.5M)
        CPU: 5min 17.030s
     CGroup: /system.slice/amavis.service
             ├─41906 "/usr/sbin/amavisd (master)"
             └─45527 "/usr/sbin/amavisd (virgin child)"

Apr 17 07:53:53 webmx amavis[44175]: (44175-01) Passed CLEAN {RelayedInbound}, [103.175.23.251]:63738 [103.175.23.251] <info@quickreviewweb.shop> ->
Apr 17 07:54:21 webmx amavis[44300]: (44300-01) Passed SPAM {RelayedTaggedInbound}, [46.17.1.212]:38948 [84.239.43.5] <fkwt34@gmail.com> -> <info@p>
Apr 17 07:54:51 webmx amavis[44447]: (44447-01) Passed CLEAN {RelayedInternal}, ORIGINATING LOCAL [127.0.0.1] <root@webmx.vbox.com.au> -> <postmast>
Apr 17 07:55:19 webmx amavis[44549]: (44549-01) Passed CLEAN {RelayedInbound}, [52.210.77.43]:60102 [52.210.77.43] <noreply@mail.bark.com> -> <info>
Apr 17 07:55:46 webmx amavis[44713]: (44713-01) Passed SPAMMY {RelayedTaggedInbound}, [23.95.24.178]:42184 [23.95.24.187] <info@solutionstation.com>
Apr 17 07:56:11 webmx amavis[44713]: (44713-01-2) Passed SPAM {RelayedTaggedInbound}, [114.222.83.215]:55754 [114.222.83.215] <pclfj@hcai.com> -> <>
Apr 17 07:56:33 webmx amavis[44713]: (44713-01-3) Passed CLEAN {RelayedInbound}, [8.221.27.162]:51088 [8.221.27.162] <alert@cqvue.com> -> <info@vor>
Apr 17 07:57:11 webmx amavis[45057]: (45057-01) Passed CLEAN {RelayedInbound}, [54.39.34.217]:16797 [15.235.66.199] <support@hotels1000.com> -> <re>
Apr 17 07:57:30 webmx amavis[45245]: (45245-01) NOTICE: reconnecting in response to: err=2013, HY000, DBD::mysql::st execute failed: Lost connectio>
Apr 17 07:57:34 webmx amavis[45245]: (45245-01) Passed SPAM {RelayedTaggedInbound}, [211.37.177.52]:63177 [211.37.177.52] <secure-account-message@e>
lines 1-22/22 (END)

However, there are remaining issue present since the Ubuntu upgrade, mainly Roundcube where I get this at the webpage

Oops... something went wrong!
An internal error has occurred. Your request cannot be processed at this time

.
And this in mail.err

 Apr 16 18:30:13 webmx roundcube: PHP Fatal error:  Uncaught Error: Undefined constant PDO::MYSQL_ATTR_FOUND_ROWS in /var/www/html/xxxx.com.au/roundcubemail/program/lib/Roundcube/db/mysql.php:129
Apr 16 18:30:13 webmx roundcube: Stack trace:
Apr 16 18:30:13 webmx roundcube: #0 /var/www/html/xxxx.com.au/roundcubemail/program/lib/Roundcube/rcube_db.php(168): rcube_db_mysql->dsn_options()
Apr 16 18:30:13 webmx roundcube: #1 /var/www/html/xxxx.com.au/roundcubemail/program/lib/Roundcube/rcube_db.php(154): rcube_db->conn_create()
Apr 16 18:30:13 webmx roundcube: #2 /var/www/html/xxxx.com.au/roundcubemail/program/lib/Roundcube/rcube_db.php(259): rcube_db->dsn_connect()
Apr 16 18:30:13 webmx roundcube: #3 /var/www/html/xxxx.com.au/roundcubemail/program/lib/Roundcube/rcube_db.php(450): rcube_db->db_connect()
Apr 16 18:30:13 webmx roundcube: #4 /var/www/html/xxxx.com.au/roundcubemail/program/lib/Roundcube/rcube_db.php(418): rcube_db->_query()
Apr 16 18:30:13 webmx roundcube: #5 /var/www/html/xxxx.com.au/roundcubemail/program/lib/Roundcube/session/db.php(113): rcube_db->query()
Apr 16 18:30:13 webmx roundcube: #6 [internal function]: rcube_session_db->read()
Apr 16 18:30:13 webmx roundcube: #7 /var/www/html/xxxx.com.au/roundcubemail/program/lib/Roundcube/rcube_session.php(141): session_start()
Apr 16 18:30:13 webmx roundcube: #8 /var/www/html/xxxx.com.au/roundcubemail/program/lib/Roundcube/rcube.php(495): rcube_session->start()
Apr 16 18:30:13 webmx roundcube: #9 /var/www/html/xxxx.com.au/roundcubemail/program/include/rcmail.php(649): rcube->session_init()
Apr 16 18:30:13 webmx roundcube: #10 /var/www/html/xxxx.com.au/roundcubemail/program/include/rcmail.php(118): rcmail->session_init()
Apr 16 18:30:13 webmx roundcube: #11 /var/www/html/xxxx.com.au/roundcubemail/program/include/rcmail.php(93): rcmail->startup()
Apr 16 18:30:13 webmx roundcube: #12 /var/www/html/xxxx.com.au/roundcubemail/index.php(43): rcmail::get_instance()
Apr 16 18:30:13 webmx roundcube: #13 {main}

If someone can please help to identify the issue(s), that have occurred only since the Ubuntu OS upgrade. Thank you.

**Vortex** · 2025-04-17 14:28:54

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Happily I now have some progress, mail is now working again, mostly due to php8.4 being installed with Ubuntu 24.04.
I have Roundcube running on Apache happily until this upgrade. I believe it's the same issue as I have made adjusts to the Apache conf to accommodate php8.4, however there remains ap problem.

Roundcube will now open on its login page, however there is an error,

"invalid request no data was saved".

Then the login produce an HTML 503 page as I was receiving before.

Anybody have any ideas please? TIA

**ZhangHuangbin** · 2025-04-17 20:58:57

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 31,361

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

This is a server with mixed Apache + Nginx, php 7.3 and 8.4, it's not a standard iRedMail installation, hence it's hard for us to give some suggestions.

**Vortex** · 2025-04-18 12:27:02

Vortex
Member
Offline

Registered: 2014-05-20
Posts: 66

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

[SOLVED]
After a lot of digging, I found the newly installed php8.4 must have extension php-intl for Roundcube.

sudo apt-get install -y php-intl

April 4, 2025: iRedMail-1.7.3 has been released.

[SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Posts: 16

1 Topic by Vortex 2025-04-16 14:47:57 (edited by Vortex 2025-04-18 12:28:07)

Topic: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

2 Reply by ZhangHuangbin 2025-04-16 14:57:13

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

3 Reply by Vortex 2025-04-16 15:11:36 (edited by Vortex 2025-04-16 15:17:55)

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

4 Reply by ZhangHuangbin 2025-04-16 15:20:47

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

5 Reply by Vortex 2025-04-16 15:30:55 (edited by Vortex 2025-04-16 15:37:11)

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

6 Reply by Vortex 2025-04-16 16:12:05 (edited by Vortex 2025-04-16 16:14:20)

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

7 Reply by Vortex 2025-04-16 17:47:34 (edited by Vortex 2025-04-16 18:16:32)

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

8 Reply by ZhangHuangbin 2025-04-16 19:23:24

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

9 Reply by Vortex 2025-04-16 19:52:34

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

10 Reply by Vortex 2025-04-16 19:54:24

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

11 Reply by Vortex 2025-04-16 20:20:03

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

12 Reply by ZhangHuangbin 2025-04-16 21:28:35

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

13 Reply by Vortex 2025-04-17 03:59:41 (edited by Vortex 2025-04-17 06:19:58)

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

14 Reply by Vortex 2025-04-17 14:28:54

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

15 Reply by ZhangHuangbin 2025-04-17 20:58:57

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

16 Reply by Vortex 2025-04-18 12:27:02 (edited by Vortex 2025-04-18 12:32:39)

Re: [SOLVED] Amavis fails after Ubuntu up from 22.02 to 24.04

Posts: 16