Bug 256974 - security/amavisd-new won't start with jail - Net::Server::Proto::UNIX, later manual start brings it up
Summary: security/amavisd-new won't start with jail - Net::Server::Proto::UNIX, later ...
Status: In Progress
Alias: None
Product: Ports & Packages
Classification: Unclassified
Component: Individual Port(s) (show other bugs)
Version: Latest
Hardware: amd64 Any
: --- Affects Only Me
Assignee: Florian Smeets
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-07-04 11:39 UTC by Marko Cupać
Modified: 2024-01-12 13:22 UTC (History)
2 users (show)

See Also:
bugzilla: maintainer-feedback? (flo)


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Marko Cupać 2021-07-04 11:39:02 UTC
Hi,

I moved two of my 12.2 jails from 12.2 to 13.0 host, and upgraded them to 13.0. During the process, all the packages were upgraded to latest main.

After the upgrade, amavisd-new won't start with jail, it throws the following:

Jul  3 18:57:03 mx amavis[76304]: (!)Net::Server: 2021/07/03-18:57:03 Unable to load module for proto "Net::Server::Proto::UNIX": Can't locate Net/Server/Proto/UNIX.pm:   lib/Net/Server/Proto/UNIX.pm: Permission denied at /usr/local/lib/perl5/site_perl/Net/Server/Proto.pm line 194, <GEN34> line 6.\n\n  at line 194 in file /usr/local/lib/perl5/site_perl/Net/Server/Proto.pm

Manual service start has no problem.

I have another identical 12.2 jail which I moved from 12.2 to 13.0 host, but haven't upgraded the jail and packages. This one has no problem.

amavisd-new is same on both jails (2.12.0_1,1), however some perl modules are higher on 13.0 (problematic) jail, including p5-Net-Server (2.009 on jail without the problem, 2.010 on jail with the problem).

Could it be that p5-Net-Server bump caused amavisd-new to refuse to start with jail, but still be able to start on later manual start?

Thank you in advance,
Comment 1 Marko Cupać 2021-09-15 14:03:28 UTC
Any news?

---jail start---
Sep 15 15:59:47 mx2 amavis[13296]: starting. /usr/local/sbin/amavisd at mx2.example.org amavisd-new-2.12.0 (20190725), Unicode aware, LANG="C.UTF-8"
Sep 15 15:59:47 mx2 amavis[13296]: perl=5.032001, user=, EUID: 110 (110);  group=, EGID: 110 110 (110 110)
Sep 15 15:59:47 mx2 amavis[13298]: (!)Net::Server: 2021/09/15-15:59:47 Unable to load module for proto "Net::Server::Proto::UNIX": Can't locate Net/Server/Proto/UNIX.pm:   lib/Net/Server/Proto/UNIX.pm: Permission denied at /usr/local/lib/perl5/site_perl/Net/Server/Proto.pm line 194.\n\n  at line 194 in file /usr/local/lib/perl5/site_perl/Net/Server/Proto.pm

---service amavisd restart inside jail---
Sep 15 16:00:11 mx2 amavis[13609]: starting. /usr/local/sbin/amavisd at mx2.example.org amavisd-new-2.12.0 (20190725), Unicode aware, LANG="C.UTF-8"
Sep 15 16:00:11 mx2 amavis[13609]: perl=5.032001, user=, EUID: 110 (110);  group=, EGID: 110 110 (110 110)
Sep 15 16:00:12 mx2 amavis[13621]: Net::Server: Group Not Defined.  Defaulting to EGID '110 110'
Sep 15 16:00:12 mx2 amavis[13621]: Net::Server: User Not Defined.  Defaulting to EUID '110'
Sep 15 16:00:12 mx2 amavis[13621]: No $altermime,         not using it
Sep 15 16:00:12 mx2 amavis[13621]: No ext program for   .F, tried: unfreeze, freeze -d, melt, fcat
Sep 15 16:00:12 mx2 amavis[13621]: No ext program for   .lrz, tried: lrzip -q -k -d -o -, lrzcat -q -k
Sep 15 16:00:12 mx2 amavis[13621]: No ext program for   .lz4, tried: lz4c -d
Sep 15 16:00:12 mx2 amavis[13621]: No ext program for   .tnef, tried: tnef
Sep 15 16:00:12 mx2 amavis[13621]: No decoder for       .F   
Sep 15 16:00:12 mx2 amavis[13621]: No decoder for       .lrz 
Sep 15 16:00:12 mx2 amavis[13621]: No decoder for       .lz4 
Sep 15 16:00:12 mx2 amavis[13621]: Using primary internal av scanner code for ClamAV-clamd
Sep 15 16:00:12 mx2 amavis[13621]: Found secondary av scanner ClamAV-clamscan at /usr/local/bin/clamscan
Comment 2 Marko Cupać 2021-10-11 10:47:31 UTC
Could it be that I am the only one experiencing this problem?

For now I have to resort to putting:

@reboot /usr/sbin/service amavisd restart > /dev/null 2>&1

...to root's crontab on four of my 13_0:x86:64 jails.
Comment 3 Dominik Wombacher 2021-12-25 21:31:20 UTC
Hey Marko,

you are not alone, i'm facing the same issue in a FreeBSD 13 jail.


/var/log/maillog, amavis failed to load during jail start:
Dec 25 22:10:59 web amavis[30737]: starting. /usr/local/sbin/amavisd at web.dominik-wombacher.de amavisd-new-2.12.0 (20190725), Unicode aware, LANG="C.UTF-8"
Dec 25 22:10:59 web amavis[30737]: perl=5.034000, user=, EUID: 110 (110);  group=, EGID: 110 110 (110 110)
Dec 25 22:10:59 web amavis[30739]: (!)Net::Server: 2021/12/25-22:10:59 Unable to load module for proto "Net::Server::Proto::UNIX": Can't locate Net/Server/Proto/UNIX.pm:   lib/Net/Server/Proto/UNIX.pm: Permission denied at /usr/local/lib/perl5/site_perl/Net/Server/Proto.pm line 194.\n\n  at line 194 in file /usr/local/lib/perl5/site_perl/Net/Server/Proto.pm

/var/log/maillog, manual start as root via "service amavisd start" is working:
Dec 25 22:11:43 web amavis[31052]: starting. /usr/local/sbin/amavisd at web.example.com amavisd-new-2.12.0 (20190725), Unicode aware, LANG="C.UTF-8"
Dec 25 22:11:43 web amavis[31052]: perl=5.034000, user=, EUID: 110 (110);  group=, EGID: 110 110 (110 110)
Dec 25 22:11:43 web amavis[31054]: Net::Server: Group Not Defined.  Defaulting to EGID '110 110'
Dec 25 22:11:43 web amavis[31054]: Net::Server: User Not Defined.  Defaulting to EUID '110'
Dec 25 22:11:43 web amavis[31054]: No $altermime,         not using it
Dec 25 22:11:43 web amavis[31054]: No ext program for   .F, tried: unfreeze, freeze -d, melt, fcat
Dec 25 22:11:43 web amavis[31054]: No ext program for   .lrz, tried: lrzip -q -k -d -o -, lrzcat -q -k
Dec 25 22:11:43 web amavis[31054]: No decoder for       .F   
Dec 25 22:11:43 web amavis[31054]: No decoder for       .lrz 
Dec 25 22:11:43 web amavis[31054]: Using primary internal av scanner code for clamav-socket
Dec 25 22:11:43 web amavis[31054]: Found secondary av scanner clamav-clamscan at /usr/local/bin/clamscan


Couldn't find a Solution yet.
Comment 4 Dominik Wombacher 2021-12-25 22:50:02 UTC
It looks like that "/usr/local/etc/rc.d/amavisd start" (and restart) always fail with the mentioned error, "service amavisd start" (and restart) is working fine. 

This would explain why it's failing on boot, as far I understand, the rc.d script will be executed and not the service command.

The Problem was mentioned 2016 as well: https://lists.freebsd.org/pipermail/freebsd-ports/2016-August/104278.html

Seems like a rare issue, maybe someone has a idea how to further troubleshoot it, my knowledge about the technical differences between running the rc.d script directly or through the service command is quite limited.
Comment 5 Florian Smeets freebsd_committer freebsd_triage 2022-02-18 12:44:02 UTC
Hi,

I suspect the latest update (2.12.2) did not change your situation?

I tried to reproduce this with every new message to this PR, I never succeeded. I even created new jails but was not successful in recreating the issue.

We'd need logs, but in a jail that's a tad more difficult that on normal hosts.

Florian
Comment 6 Zilon 2022-02-18 14:15:37 UTC
Hello,

I observe the same behavior on my system (FreeBSD 13.0 -p6) and amavisd-new-2.12.0_1,1. It starts if I run the sevice command manually but does not start automatically if the jail is restarted.

Using the latest version 2.12.2,1, amavisd does not start at all. The only message I receive is "/usr/local/etc/rc.d/amavisd: WARNING: failed to start amavisd"

Any hints?

Thank you in advance!
Comment 7 Florian Smeets freebsd_committer freebsd_triage 2022-02-18 14:47:02 UTC
(In reply to Zilon from comment #6)

No, without any logs I have not hint. Please look at /var/log/messages, /var/log/maillog try starting /usr/local/sbin/amavisd by hand as root, you should see an error message.

For me 2.12.2 is successfully running on 2 hosts and one jail.
Comment 8 Zilon 2022-02-18 15:16:56 UTC
(In reply to Florian Smeets from comment #7)
There was no information in the logs excapt that the start failed.

Your hint to run /usr/local/sbin/amavisd directly as root finally led to the solution. Thank you very much! 

I had to adjust the permissions for my amavisd.conf file. I have no idea why the permission requirements changed from one version to the other but it seems to be the rootcause.

The issue that amavisd is not starting when the jail is restarted, is not solved with the recent version.
Comment 9 Marko Cupać 2024-01-12 13:22:27 UTC
(In reply to Florian Smeets from comment #7)

Hi,

the problem is still present on 14.0-RELEASE-p4 with amavisd-new-2.12.2_1,1, on three instances (does not start with jail, starts fine with root cron `@reboot /usr/sbin/service amavisd restart` or with manual `service amavisd (re)|start`).

Message from amavis.log is similar:

Jan 12 14:14:46 mx2 amavis[74891]: (!)Net::Server: 2024/01/12-14:14:46 Unable to load module for proto "Net::Server::Proto::UNIX": Can't locate Net/Server/Proto/UNIX.pm:   lib/Net/Server/Proto/UNIX.pm: Permission denied at /usr/local/lib/perl5/site_perl/Net/Server/Proto.pm line 195.\n\n  at line 195 in file /usr/local/lib/perl5/site_perl/Net/Server/Proto.pm

I would be glad to provide more logs