dovecot - Nov 2012 - dovecot: lda(root): Fatal: Invalid user settings. Refer to server log for more information.

I ran dovecot -a and the blizzard of data seemed ok to my limited 
knowledge.  Is there another log I should look into to trace this error 
down?

Dovecot and system info:

thufir at dur:~$
thufir at dur:~$ dovecot --version
2.0.19
thufir at dur:~$
thufir at dur:~$ cat /etc/lsb-release
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=12.04
DISTRIB_CODENAME=precise
DISTRIB_DESCRIPTION="Ubuntu 12.04.1 LTS"
thufir at dur:~$



testing postfix & dovecot 
(http://packages.ubuntu.com/precise/dovecot-postfix):

root at dur:/etc/postfix#
root at dur:/etc/postfix# telnet localhost 25
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
220 dur.bounceme.net ESMTP Postfix (Ubuntu)
helo me
250 dur.bounceme.net
mail from:foo at bar.com
250 2.1.0 Ok
rcpt to:root at dur.bounceme.net
250 2.1.5 Ok
data
354 End data with <CR><LF>.<CR><LF>
subject:ping 3
blah blah
.
250 2.0.0 Ok: queued as 35EC92A0D72
quit
221 2.0.0 Bye
Connection closed by foreign host.
root at dur:/etc/postfix#
root at dur:/etc/postfix# tail /var/log/mail.log
Nov 16 12:30:07 dur postfix/smtpd[4113]: connect from localhost[127.0.0.1]
Nov 16 12:30:40 dur postfix/smtpd[4113]: 35EC92A0D72: 
client=localhost[127.0.0.1]
Nov 16 12:30:52 dur postfix/cleanup[4133]: 35EC92A0D72: 
message-id=<20121116203040.35EC92A0D72 at dur.bounceme.net>
Nov 16 12:30:52 dur postfix/qmgr[1681]: 35EC92A0D72: from=<foo at
bar.com>,
size=321, nrcpt=1 (queue active)
Nov 16 12:30:52 dur dovecot: lda(root): Error: chdir(/root/) failed: 
Permission denied (euid=65534(nobody) egid=65534(nogroup) missing +x 
perm: /root, dir owned by 0:0 mode=0700)
Nov 16 12:30:52 dur dovecot: lda(root): Error: chdir(/root) failed: 
Permission denied
Nov 16 12:30:52 dur dovecot: lda(root): Error: user root: Initialization 
failed: Initializing mail storage from mail_location setting failed: 
stat(/root/Maildir) failed: Permission denied (euid=65534(nobody) 
egid=65534(nogroup) missing +x perm: /root, dir owned by 0:0 mode=0700)
Nov 16 12:30:52 dur dovecot: lda(root): Fatal: Invalid user settings. 
Refer to server log for more information.
Nov 16 12:30:52 dur postfix/local[4134]: 35EC92A0D72: 
to=<root at dur.bounceme.net>, relay=local, delay=25, 
delays=25/0.02/0/0.12, dsn=4.3.0, status=deferred (temporary failure)
Nov 16 12:30:56 dur postfix/smtpd[4113]: disconnect from 
localhost[127.0.0.1]
root at dur:/etc/postfix#




thanks,

Thufir

On Fri, Nov 16, 2012 at 12:47:52PM -0800, Thufir wrote:
> I ran dovecot -a and the blizzard of data seemed ok to my limited
> knowledge.  Is there another log I should look into to trace this
> error down?
It's actually a Postfix problem. Postfix is invoking your Dovecot LDA 
with wrong permissions.
> Dovecot and system info:
> 
> thufir at dur:~$
> thufir at dur:~$ dovecot --version
> 2.0.19
> thufir at dur:~$
> thufir at dur:~$ cat /etc/lsb-release
> DISTRIB_ID=Ubuntu
> DISTRIB_RELEASE=12.04
> DISTRIB_CODENAME=precise
> DISTRIB_DESCRIPTION="Ubuntu 12.04.1 LTS"
> thufir at dur:~$
> 
> testing postfix & dovecot
> (http://packages.ubuntu.com/precise/dovecot-postfix):
> 
> root at dur:/etc/postfix#
> root at dur:/etc/postfix# telnet localhost 25
> Trying 127.0.0.1...
> Connected to localhost.
> Escape character is '^]'.
> 220 dur.bounceme.net ESMTP Postfix (Ubuntu)
> helo me
> 250 dur.bounceme.net
> mail from:foo at bar.com
Angle brackets are required on envelope addresses (and I bet you 
don't own bar.com):

MAIL FROM:<foo at example.com>
> 250 2.1.0 Ok
> rcpt to:root at dur.bounceme.net
RCPT TO:<root at dur.bounceme.net>
> 250 2.1.5 Ok
> data
> 354 End data with <CR><LF>.<CR><LF>
> subject:ping 3
> blah blah
> .
A header must have a space after the colon. Header and body are 
separated by a blank line. See RFC 5322.
> 250 2.0.0 Ok: queued as 35EC92A0D72
> quit
> 221 2.0.0 Bye
> Connection closed by foreign host.
> root at dur:/etc/postfix#
> root at dur:/etc/postfix# tail /var/log/mail.log
> Nov 16 12:30:07 dur postfix/smtpd[4113]: connect from localhost[127.0.0.1]
> Nov 16 12:30:40 dur postfix/smtpd[4113]: 35EC92A0D72:
> client=localhost[127.0.0.1]
> Nov 16 12:30:52 dur postfix/cleanup[4133]: 35EC92A0D72:
> message-id=<20121116203040.35EC92A0D72 at dur.bounceme.net>
> Nov 16 12:30:52 dur postfix/qmgr[1681]: 35EC92A0D72:
> from=<foo at bar.com>, size=321, nrcpt=1 (queue active)
> Nov 16 12:30:52 dur dovecot: lda(root): Error: chdir(/root/) failed:
> Permission denied (euid=65534(nobody) egid=65534(nogroup) missing +x
> perm: /root, dir owned by 0:0 mode=0700)
The fix to this is simply not to deliver mail to root. You should 
have aliased root to a mortal user. Postfix will not invoke a 
mailbox_command as root.

In broader terms, you should only use root for actual system 
administration, and not for user tasks such as reading and sending 
mail.

See and edit /etc/aliases, then run "newaliases". Example:

root:	thufir

http://www.postfix.org/postconf.5.html#default_privs
http://www.postfix.org/postconf.5.html#mailbox_command
http://www.postfix.org/local.8.html
http://www.postfix.org/aliases.5.html

After you have done this, requeue the message:

# postsuper -r 35EC92A0D72

(or just delete it, s/-r/-d/, and try another test.)

http://www.postfix.org/postsuper.1.html
> Nov 16 12:30:52 dur dovecot: lda(root): Error: chdir(/root) failed:
> Permission denied
> Nov 16 12:30:52 dur dovecot: lda(root): Error: user root:
> Initialization failed: Initializing mail storage from mail_location
> setting failed: stat(/root/Maildir) failed: Permission denied
> (euid=65534(nobody) egid=65534(nogroup) missing +x perm: /root, dir
> owned by 0:0 mode=0700)
> Nov 16 12:30:52 dur dovecot: lda(root): Fatal: Invalid user settings.
> Refer to server log for more information.
> Nov 16 12:30:52 dur postfix/local[4134]: 35EC92A0D72:
> to=<root at dur.bounceme.net>, relay=local, delay=25,
> delays=25/0.02/0/0.12, dsn=4.3.0, status=deferred (temporary failure)
> Nov 16 12:30:56 dur postfix/smtpd[4113]: disconnect from
> localhost[127.0.0.1]
> root at dur:/etc/postfix#
-- 
  http://rob0.nodns4.us/ -- system administration and consulting
  Offlist GMX mail is seen only if "/dev/rob0" is in the Subject:

At 12PM -0800 on 16/11/12 you (Thufir) wrote:
> I ran dovecot -a and the blizzard of data seemed ok to my limited 
> knowledge.  Is there another log I should look into to trace this error 
> down?
<snip>
> 
> Nov 16 12:30:52 dur dovecot: lda(root): Error: chdir(/root/) failed: 
> Permission denied (euid=65534(nobody) egid=65534(nogroup) missing +x 
> perm: /root, dir owned by 0:0 mode=0700)
> Nov 16 12:30:52 dur dovecot: lda(root): Error: chdir(/root) failed: 
> Permission denied
> Nov 16 12:30:52 dur dovecot: lda(root): Error: user root: Initialization 
> failed: Initializing mail storage from mail_location setting failed: 
> stat(/root/Maildir) failed: Permission denied (euid=65534(nobody) 
> egid=65534(nogroup) missing +x perm: /root, dir owned by 0:0 mode=0700)
> Nov 16 12:30:52 dur dovecot: lda(root): Fatal: Invalid user settings. 
> Refer to server log for more information.
You should not be attempting to deliver mail to root directly. Instead
you should forward root's mail to a real user with /etc/aliases;
postfix's local(8) will not allow you to deliver mail as root.

Ben

On Fri, 16 Nov 2012 16:09:54 -0600, /dev/rob0 wrote:

> The fix to this is simply not to deliver mail to root. You should have
> aliased root to a mortal user. Postfix will not invoke a mailbox_command
> as root.
>
> In broader terms, you should only use root for actual system
> administration, and not for user tasks such as reading and sending mail.
>
> See and edit /etc/aliases, then run "newaliases". Example:
>
> root:	thufir
>
> http://www.postfix.org/postconf.5.html#default_privs
> http://www.postfix.org/postconf.5.html#mailbox_command
> http://www.postfix.org/local.8.html
> http://www.postfix.org/aliases.5.html
>
> After you have done this, requeue the message:
>
> # postsuper -r 35EC92A0D72
>
> (or just delete it, s/-r/-d/, and try another test.)
>
> http://www.postfix.org/postsuper.1.html

Ah, thank you.  Not dovecot at all, makes sense.  I was sending to root
because of a problem with keychain preventing usage of the "mail" 
command for users:

http://ubuntuforums.org/showthread.php?t=2065461

Anyhow, that's fixed so that I can now use the "mail" command as a
mortal, as you put it.  I think I'm on my way, and that this is a 
postfix and not dovecot problem.  The mail doesn't arrive, but the log 
shows as delivered (I think) and then removed for some reason:

thufir at dur:~$
thufir at dur:~$
thufir at dur:~$ telnet localhost 25
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
220 dur.bounceme.net ESMTP Postfix (Ubuntu)
HELO me
250 dur.bounceme.net
mail from:<thufir at example.com>
250 2.1.0 Ok
rcpt to:<thufir at localhost>
250 2.1.5 Ok
data
354 End data with <CR><LF>.<CR><LF>
subject: never arrives

postfix problem?
.
250 2.0.0 Ok: queued as 3C8392A0007
quit
221 2.0.0 Bye
Connection closed by foreign host.
thufir at dur:~$
thufir at dur:~$ mail
No mail for thufir
thufir at dur:~$
thufir at dur:~$
thufir at dur:~$ tail /var/log/mail.log
Nov 16 17:19:04 dur postfix/smtpd[2975]: connect from localhost[127.0.0.1]
Nov 16 17:19:32 dur postfix/smtpd[2975]: disconnect from localhost
[127.0.0.1]
Nov 16 17:19:36 dur postfix/smtpd[2975]: connect from localhost[127.0.0.1]
Nov 16 17:20:06 dur postfix/smtpd[2975]: 3C8392A0007: client=localhost
[127.0.0.1]
Nov 16 17:20:48 dur postfix/cleanup[2985]: 3C8392A0007: message-
id=<20121117012006.3C8392A0007 at dur.bounceme.net>
Nov 16 17:20:48 dur postfix/qmgr[1521]: 3C8392A0007:
from=<thufir at example.com>, size=336, nrcpt=1 (queue active)
Nov 16 17:20:48 dur dovecot: lda(thufir):
msgid=<20121117012006.3C8392A0007 at dur.bounceme.net>: saved mail to
INBOX
Nov 16 17:20:48 dur postfix/local[2988]: 3C8392A0007:
to=<thufir at localhost>, relay=local, delay=55, delays=55/0.02/0/0.17,
dsn=2.0.0, status=sent (delivered to command: /usr/lib/dovecot/deliver -
c /etc/dovecot/conf.d/01-mail-stack-delivery.conf -m "${EXTENSION}")
Nov 16 17:20:48 dur postfix/qmgr[1521]: 3C8392A0007: removed
Nov 16 17:20:54 dur postfix/smtpd[2975]: disconnect from localhost
[127.0.0.1]
thufir at dur:~$



thanks,

Thufir