# amavisd-new broken after update, permissions issue [SOLVED]

## epig

Hi all, 

Updated my amavisd-new this morning and it broke somehow. 

Now, in the /var/log/mail/current, there is no trace of the usual startup logging. Zip, Zilch. Nada.

Starting the service returns an OK, but no processes spawn. 

Starting just the binary, however, returns: 

```
grond ~ # amavisd

Error reading config file "/etc/amavisd.conf": Permission denied at /usr/sbin/amavisd line 2238.

```

Version info: 

amavisd-new-2.12.2 (20211013)

with no logging, I am stumped... 

Anyone have a pointer or two?Last edited by epig on Mon Feb 28, 2022 12:49 pm; edited 1 time in total

----------

## epig

Upon further investigation, it seems that the update had taken away all read rights in the /etc/amavisd.conf file. 

```
 # ls -lah /etc/amavisd.conf

-rwx------ 1 root 206 116K Feb 28 13:19 /etc/amavisd.conf

```

So after running a 

```
chmod 744 /etc/amavisd.conf
```

the permissions seem to work OK and the service starts just fine: 

```

 # ls -lah /etc/amavisd.conf

-rwxr--r-- 1 root 206 116K Feb 28 13:19 /etc/amavisd.conf

```

I thought I'd just leave it here, since osmeonw else might come across the same problem...

----------

## freke

```
 # ls -lah /etc/amavisd.conf

-rwx------ 1 root 206 116K Feb 28 13:19 /etc/amavisd.conf
```

Unknown group-ownership?

----------

## epig

 *freke wrote:*   

> 
> 
> ```
>  # ls -lah /etc/amavisd.conf
> 
> ...

 

Could be, not sure. 

Works after setting proper config file permissions, anyway.

----------

## Hu

Configuration files are normally not executable.  644 would be more traditional.  Are you sure the file was world-readable before the update?  It could be that the file was always mode 600, but that older versions of the script read the file while still running as root, and the new version changes to an unprivileged user before reading the file.

----------

## epig

 *Hu wrote:*   

> Configuration files are normally not executable.  644 would be more traditional.  Are you sure the file was world-readable before the update?  It could be that the file was always mode 600, but that older versions of the script read the file while still running as root, and the new version changes to an unprivileged user before reading the file.

 

Yes, 644 is correct (and works). Let's call it a typo...

Could have been a change in permissions, but usually that shows up in the patch notes/package comments. Didn't see that here. 

IF the file was 600, that no longer worked, so 644 it is.

----------

## deagol

Got bitten by the same issue: System updated bumped amavisd from 2.12.1 to 2.12.2. After the update the service was not working and calling it manually produced the exact same error as you got.

I'm sure the permission of /etc/amavisd.conf was not changed during the update, I still have the btrfs snapshot showing the old file permission:

```
-rw-r-----. 1 root root system_u:object_r:amavis_etc_t 37118 Jan 14  2017 amavisd.conf
```

While debugging it I was able to link the problem to the first usage of $! in the line 2238 from /usr/sbin/amavisd:

```
 elsif ($! != 0)  { die "Error reading config file \"$config_file\": $!" }
```

Commenting out that line worked, also changing the elsif to "0 != 0".

Now changing /etc/amavisd.conf to 644 also fixed the issue for me, It looks like for some strange. After all it looks like the usage of $! caused the error, there was no message that the config file was unreadable...

It's working now but if someone can explain the reason why I would be very interested...

----------

## epig

 *deagol wrote:*   

> 
> 
> Commenting out that line worked, also changing the elsif to "0 != 0".
> 
> Now changing /etc/amavisd.conf to 644 also fixed the issue for me, It looks like for some strange. After all it looks like the usage of $! caused the error, there was no message that the config file was unreadable...
> ...

 

Surely this must be a bug of some kind?

----------

## Hu

I could believe that the newer daemon switches to an unprivileged user early in startup. *deagol wrote:*   

> Commenting out that line worked, also changing the elsif to "0 != 0".

 Removing error handling usually does silence the error reporting. *deagol wrote:*   

> Now changing /etc/amavisd.conf to 644 also fixed the issue for me, It looks like for some strange. After all it looks like the usage of $! caused the error, there was no message that the config file was unreadable...

 That is exactly the message the OP reported at the start: Permission denied at /usr/sbin/amavisd line 2238.

----------

## Duncan Mac Leod

...will this be fixed in an updated ebuild ?

----------

## figueroa

Seriously, who/what is group 206? Fix that.

----------

## Hu

 *deagol wrote:*   

> I'm sure the permission of /etc/amavisd.conf was not changed during the update, I still have the btrfs snapshot showing the old file permission:
> 
> ```
> -rw-r-----. 1 root root system_u:object_r:amavis_etc_t 37118 Jan 14  2017 amavisd.conf
> ```
> ...

 This is not the permissions that the OP reported.  However, it is also not consistent with what the ebuild seems to set:

```
    # The config file should be root:amavis so that the amavis user can

    # read (only) it after dropping privileges. And of course he should

    # own everything in his home directory.

    insinto /etc

    insopts -m0640 -g amavis

    doins amavisd.conf
```

 *Duncan Mac Leod wrote:*   

> ...will this be fixed in an updated ebuild ?

 Is there an open bug report that describes what needs to be changed?

----------

## MoonWalker

Ok ran in to this as well, so bringing the topic back to life. Still haven't got it working, so will make a try here incase someone got to it w/o sharing the solution. Here is some output from my box:

 *Quote:*   

> merc # /etc/init.d/amavisd restart
> 
>  * Stopping amavisd ...
> 
>  * start-stop-daemon: no matching processes found                                                             [ ok ]
> ...

 

merc is the name of my box.

Something strange is definitely going on as the pid is there but still no process according to ps. Also, after the update it stopped to write to /var/lib/amavishome/amavis.log nor is it recreated if removed. So apparently, something is stopping amavisd from starting for real.

I tried changing permissions on amavis.conf but it yielded nothing.

----------

## Duncan Mac Leod

Cannot confirm this!

Updated 4 Gentoo boxes, checked all files before and after installation.

No file permissions have been altered during installation...

----------

## MoonWalker

so your amavisd runs okay?

----------

## MoonWalker

I opened a bug for this issue:

https://bugs.gentoo.org/836768

----------

## Duncan Mac Leod

 *MoonWalker wrote:*   

> so your amavisd runs okay?

 

YES - runs without any issues.

----------

## MoonWalker

 *Duncan Mac Leod wrote:*   

>  *MoonWalker wrote:*   so your amavisd runs okay? 
> 
> YES - runs without any issues.

 

Do you have a amavisd file in /etc/conf.d/ ?

I notice when running  *Quote:*   

> # /etc/init.d/amavisd -d start

  it check for a file there (which I don't have), but maybe it's just a general script check. I don't know.

 *Quote:*   

> # amavisd -d start
> 
> merc ~ # /etc/init.d/amavisd -d start
> 
> + sourcex -e /etc/rc.conf
> ...

 

I'm not really able to read out what that output actually is saying, more than  'Failed to start amavisd' and not that I understand it, but something tells me that it may have something to do with cgroup, which I don't really know anything about.

----------

## Duncan Mac Leod

No, I don't have anything amavisd-new related under /etc/conf.d

my config file is: /etc/amavisd.conf

----------

## MoonWalker

Well, I am lost as it doesn't write anything to the log file as if it doesn't even try to start!

The only thing I can get out of the mail log is  *Quote:*   

> Apr 04 22:16:02 [/etc/init.d/amavisd] start-stop-daemon: no matching processes found

  but that doesn't come from amavisd as I have it configured to write to its own file.

It's probably some freaking small detail in my system but I cannot see it!

The only think that I possibly can think of is that I am still on profile 17.0, could that be it?

I'm in the process to upgrade, but not there yet.

----------

## deagol

Nothing new to the careful reader but I want to point out that the correct fix for the epig and also me was basically:

```
  chgrp amavis /etc/amavisd.conf

  chmod 0640 /etc/amavisd.conf
```

This sets the permissions to what you would get when you install amavisd-new fresh nowadays.

Looks like up to 2.12.2 amavisd-new was still running as root when the config file was parsed and the "wrong" permissions were ok. Starting with 2.12.2 root gets dropped prior to parsing the config files and installations with the wrong permissions get issues.

Not nice but I would not rate that as a bug. This is just something which happens from time to time with rolling releases.

The bug here for me is, that the correct error message is too verbose. It would probably be more helpful to just get something like Error reading config file /etc/amavisd.conf

edit:

fixed incorrect statement about the error message. It's printed out

----------

## MoonWalker

Maybe my issue is different then because /etc/amavisd.conf permissions are as it should be. 

 *Quote:*   

> merc ~ # ls -l /etc/amavisd.conf
> 
> -rw-r----- 1 root amavis 106574 Apr  4 22:31 /etc/amavisd.conf
> 
> merc ~ # /etc/init.d/amavisd restart
> ...

 

EDIT: I also tried to change owner to amavis, but still no go.

It simply doesn't work, it simply doesn't try to start, it simply doesn't create any process and it simply doesn't write anything to the logs! However, it does create /run/amavisd.pid 

And I simply have to wait and see if my opened bug yields any new insight and hopefully a solution. Fact is, it worked before I upgraded and as there is only 1 ebuild there is no way to downgrade - but also worth keeping in mind is that I also upgraded a batch of other packages at the same time and that may have something to do with it. Well as it works for others, it kind of has to be some external circumstance that is causing this.

BTW I also tried to make that edit in the /usr/sbin/amavisd file to no avail.

----------

## MoonWalker

Ok I am trying to take another approach to this by looking at the time stamp in the mail queue (using webmin) for the first email rejected by postfix w/  *Quote:*   

> delivery temporarily suspended: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused

  and  *Quote:*   

> connect to 127.0.0.1[127.0.0.1]:10024: Connection refused

  that's the 2 error messages that shows up in the mail log, but it's from postfix and I know that's because amasivd isn't running.

But looking at these timestamps and also checking in the emerge.log file I have reached the somewhat embarrassing conclusion that this may not be a bug in amavis after all. Indeed, amavisd-new-2.12.2 was first installed om 3 March and this issue started after noon on the 31 March. I have then emerged it again only after that date. Fact remains though, emails are not delivered but queued up due to amavisd not starting/running.

I will dig deeper in the historic data to see if I can come up with a suspect, well basically dig out what was emerged ahead of mail deliveries stopped.

----------

## MoonWalker

how can I check if /usr/sbin/amavisd is even accessed ? I mean is there some code I can put that somehow confirms to me that it's accessed?

I mean, /usr/sbin/amavisd is perl, right?

----------

## MoonWalker

My investigation of the logs has revealed the following:

 *Quote:*   

> All on 31 March
> 
> at 12:14 I got my last email delivered to inbox
> 
> at 12:27 emerge update of glibc completed
> ...

 

So for a moment I though it could be a glibc "reboot needed" issue.

However, before a reboot I updated my kernel to 4.19.237 (from 4.19.2 :Cool:  as I have had issues rebooting remotely with the old kernel. I then rebooted my system remotely, successfully.

That didn't change the situation though, amavisd still refuses to start a process but creates a pid (as if it was running, which isn't the case).

I am now making a full #emerge --emptytree @world rebuild, and then I will change profile to 17.1 no-multilib and rebuild again.

If that doesn't solve it... I don't know what to do.

----------

## Hu

If the pid file exists, then the process started and wrote a pid file.  The process may have died shortly thereafter and not cleaned out the pid file.

----------

## MoonWalker

 *Hu wrote:*   

> If the pid file exists, then the process started and wrote a pid file.  The process may have died shortly thereafter and not cleaned out the pid file.

 

Is there any way I can trace this actually is happening? I am doubtful, because wouldn't that mean /usr/sbin/amavisd would run and make a log entry?

----------

## papahuhn

@MoonWalker, I can reproduce your symptoms on a fresh "generic/gentoo" Vagrantbox. In mail.log I see

 *Quote:*   

> Apr  7 09:52:34 gentoo amavis[14002]: (!)Net::Server: 2022/04/07-09:52:34 Can't connect to UNIX socket at file /var/amavis/amavisd.sock [No such file or directory]\n  at line 66 in file /usr/lib64/perl5/vendor_perl/5.34/Net/Server/Proto/UNIX.pm

 

This helps:

 *Quote:*   

> $MYHOME = '/var/lib/amavishome';

 

----------

## MoonWalker

I already have  *Quote:*   

> $MYHOME = '/var/lib/amavishome';

 in amavisd.conf, so that's not the problem, and yes the problem hasn't gone away.

Meanwhile, I have updated my system so it now uses profile 17.1, recompiled everything, but no change. amavisd simply doesn't start and it doesn't leave any clue in the logs, nothing! I am lost   :Sad: 

Also, the bug I opened hasn't yielded anything. It was assigned but the assignee hasn't showed up... but hey, my issue is clearly not the same as the OP and the topic has also been marked as [SOLVED], so I will stop  adding here and open my own thread instead.

----------

## MoonWalker

Actually, wont open a new topic as I found the cause of the issue and was able to solve it, sort of.

Not sure why I didn't come to think of this earlier, but eventually I got the idea to run /use/sbin/amavisd directly from the command line, which resulted in

 *Quote:*   

> merc ~ # amavisd
> 
> Error in config file "/etc/amavisd.conf": Can't open PEM file /var/db/dkim/mydomain-com.key.pem: Permission denied at /usr/sbin/amavisd line 639.

 

so after commenting out  *Quote:*   

> #$enable_dkim_verification = 1;  # enable DKIM signatures verification
> 
> #$enable_dkim_signing = 1;    # load DKIM signing code, keys defined by dkim_key
> 
> #dkim_key('astrocalc.com', 'mydkim',  '/var/db/dkim/mydomain-com.key.pem', k=>'rsa');

 

amavisd now starts and runs properly, and emails are delivered, although this is not a long term plausible solution.

----------

## papahuhn

 *Quote:*   

> amavisd now starts and runs properly, and emails are delivered, although this is not a long term plausible solution.

 

The long term solution would be to make the pem file readable for amavis, I guess?

----------

## papahuhn

 *Quote:*   

> So from what I can understand, something external must have changed here related to this. Not quite sure what yet, but I will take it to the forums as I see now that this most likely isn't an amavisd bug.

 

Amavis changed.

 *Quote:*   

> amavis-2.12.2 release notes
> 
> Resolve crash on reload with insufficient permissions. Amavis now tests whether it is able read and evaluate its configuration files with dropped privileges. In case it cannot, amavis fails to start and refuses to reload.

 

https://gitlab.com/amavis/amavis/-/issues/10

----------

## MoonWalker

 *papahuhn wrote:*   

>  *Quote:*   amavisd now starts and runs properly, and emails are delivered, although this is not a long term plausible solution. 
> 
> The long term solution would be to make the pem file readable for amavis, I guess?

 

I suppose so, but I'm not up-to-date on this stuff as my dkim PEMs were created in 2009 and I don't even remember how I created them.

----------

## MoonWalker

 *papahuhn wrote:*   

>  *Quote:*   So from what I can understand, something external must have changed here related to this. Not quite sure what yet, but I will take it to the forums as I see now that this most likely isn't an amavisd bug. 
> 
> Amavis changed.
> 
>  *Quote:*   amavis-2.12.2 release notes
> ...

 

Great dig up, thanks. I will take a look at that bug and see what I can learn. It's a bit odd though as I learned from grepping through the emerge.log, amavis didn't start to misbehave directly after I installed 2.12.2 but some days later, and right after I installed glibc-2.35-r2

Anyway, now I know what the issue is and the simple solution right now is probably to change ownership of those PEM files. However, as they are owned by root:root you don't just want to get on to that right away but do some investigation first.

----------

## freke

 *MoonWalker wrote:*   

>  *papahuhn wrote:*    *Quote:*   So from what I can understand, something external must have changed here related to this. Not quite sure what yet, but I will take it to the forums as I see now that this most likely isn't an amavisd bug. 
> 
> Amavis changed.
> 
>  *Quote:*   amavis-2.12.2 release notes
> ...

 

I would expect that root:amavis (and a 640 permission) for the PEMs should work.

----------

## MoonWalker

 *freke wrote:*   

> I would expect that root:amavis (and a 640 permission) for the PEMs should work.

 

Yes, that's what I ended up with as I don't think they are used by anyone else. It would be postfix and/or dovecot in such case but hasn't noticed anything so far.

----------

