Re: suddenly 'User unknown'?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Patrick, Javier, at last progress. Brilliant. :-) See below.

On 30/11/2018 14:16, Patrick Boutilier wrote:
On 11/30/18 10:00 AM, Charles Bradshaw via Info-cyrus wrote:
Javier

On 30/11/2018 11:49, Javier Angulo wrote:
On 11/29/18 8:00 PM, Charles Bradshaw via Info-cyrus wrote:
Now you tell me is cyrus syslog being sent to /var/log/maillog? Or
should it be going to /var/imapd.log as the configuration files, man
pages and cyrus installation guides ( found here:
https://www.cyrusimap.org/imap/installing.html ) say it should?
I believe there is no "syslog_facility:" option in cyrus 2.4 (at least I
was unable to find it). You can configure it in cyrus3 and maybe in
cyrus 2.5.
I removed syslog_facility from imapd.conf
So in /etc/imapd.conf I would remove the syslog_facility line and set:
syslog_prefix: cyrus
Has no effect: present or not, or changed to test.
And in /etc/rsyslog.conf:
mail.*       -/var/log/maillog
Has always been in my rsyslog.conf

Restart rsyslog and check logs for cyrus/something ...

# /etc/init.d/rsyslog restart

# service sendmail restart

Now when I connect (from another host) using Thunderbird Mail I see in
/etc/maillog:

Nov 30 13:01:02 dell2600-1 sendmail[9865]: NOQUEUE: stopping daemon,
reason=signal
Nov 30 13:01:02 dell2600-1 sendmail[9950]: starting daemon (8.14.4):
SMTP+queueing@01:00:00
Nov 30 13:01:02 dell2600-1 sendmail[9950]: STARTTLS: CRLFile missing
Nov 30 13:01:03 dell2600-1 sendmail[9950]: STARTTLS=server,
Diffie-Hellman init, key=1024 bit (1)
Nov 30 13:01:03 dell2600-1 sendmail[9950]: STARTTLS=server, init=1
Nov 30 13:01:03 dell2600-1 sendmail[9950]: started as:
/usr/sbin/sendmail -bd -q1h
Nov 30 13:01:03 dell2600-1 sm-msp-queue[9960]: starting daemon (8.14.4):
queueing@01:00:00
Nov 30 13:01:26 dell2600-1 cyrus/imaps[8645]: USAGE
brad@xxxxxxxxxxxxxxxxxxxxx user: 0.141978 sys: 0.087986
Nov 30 13:05:59 dell2600-1 cyrus/imaps[8743]: starttls: TLSv1.2 with
cipher AES128-SHA (128/128 bits new) no authentication
Nov 30 13:05:59 dell2600-1 cyrus/imaps[8743]: login: [192.168.0.6]
brad@xxxxxxxxxxxxxxxxxxxxx CRAM-MD5+TLS User logged in
SESSIONID=<cyrus-8743-1543583158-1>
Nov 30 13:05:59 dell2600-1 cyrus/imaps[8743]: client id: "name"
"Thunderbird" "version" "60.2.1"

Hum.. cyrus/imaps sends logging to /etc/maillog

I think it is absolutely clear:

1 - where cyrus syslog goes to is a red herring. It goes to, and has
always gone to /var/maillog. It is simply that the prefix 'cyrus' only
appears for cyrus imap transactions and other sendmail is labeled 'sendmail'

2 - imapd is working fine: allows brad.bradcan.homelinux.com to connect
an email client. Also to move email from one mailbox to another. The
proof is that since enabling telemetry logging
/var/lib/imap/log/brad@xxxxxxxxxxxxxxxxxxxxx/ reflects imap transactions.

3 - A problem remains with LMTP. as is clearly evident from 'User
unknown' appearing in maillog.

My original question remains: How do I diagnose this when a test email
is sent to brad@xxxxxxxxxxxxxxxxxxxxx :

Nov 30 12:59:48 dell2600-1 sendmail[9882]: wAUCxmBS009882:
to=brad@xxxxxxxxxxxxxxxxxxxxx, delay=00:00:00, xdelay=00:00:00,
mailer=cyrusv2, pri=32701, relay=localhost [[UNIX:
/var/lib/imap/socket/lmtp]], dsn=5.1.1, stat=User unknown


I think why people are concentrating on the logging is that there should be lmtp entries in your logs to indicate what the issue is. Are there any lmtp entries in either /etc/maillog or /var/log/maillog ?

The only lmtp entries are the one shown above.

I do # cat /var/log/maillog | grep lmtp

Nov 30 12:59:48 dell2600-1 sendmail[9882]: wAUCxmBR009882: to=<brad@xxxxxxxxxxxxxxxxxxxxx>, delay=00:00:00, xdelay=00:00:00, mailer=cyrusv2, pri=31677, relay=localhost [[UNIX: /var/lib/imap/socket/lmtp]], dsn=5.1.1, stat=User unknown



Another option is to limit lmtpd to one process and strace it.

If I do:

[root@dell2600-1 brad]# ps -A | grep lmtp
10146 ?        00:00:00 lmtpd

[root@dell2600-1 brad]# strace -p 10146
Process 10146 attached
accept(4, 0, NULL)                      = 11
fcntl64(10, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
alarm(0)                                = 0
write(3, "\2\0\0\0\242'\0\0", 8)        = 8
dup2(11, 0)                             = 0
dup2(11, 1)                             = 1
dup2(11, 2)                             = 2
close(11)                               = 0
write(3, "\3\0\0\0\242'\0\0", 8)        = 8
time(NULL)                              = 1543588732
getpeername(0, {sa_family=AF_LOCAL, NULL}, [2]) = 0
open("/var/lib/imap/log/postman/lmtpunix-10146", O_WRONLY|O_CREAT|O_APPEND, 0644) = -1 ENOENT (No such file or directory)
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "220 dell2600-1.bradcan.homelinux"..., 94) = 94
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 999704})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "LHLO bradcan.homelinux.com\r\n", 4096) = 28
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "250-dell2600-1.bradcan.homelinux"..., 139) = 139
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 997839})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "MAIL From:<brad@bradcan.homelinu"..., 4096) = 49
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "250 2.1.0 ok\r\n", 14)        = 14
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 998503})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "RCPT To:<brad>\r\nDATA\r\n", 4096) = 22
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
fcntl64(6, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
fstat64(6, {st_mode=S_IFREG|0600, st_size=22204, ...}) = 0
stat64("/var/lib/imap/mailboxes.db", {st_mode=S_IFREG|0600, st_size=22204, ...}) = 0
fcntl64(6, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "550-Mailbox unknown.  Either the"..., 174) = 174
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 999990})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "RSET\r\n", 4096)               = 6
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "250 2.0.0 ok SESSIONID=<cyrus-10"..., 51) = 51
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 932516})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "RSET\r\n", 4096)               = 6
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "250 2.0.0 ok SESSIONID=<cyrus-10"..., 51) = 51
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 999995})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "MAIL From:<> SIZE=1677\r\n", 4096) = 24
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "250 2.1.0 ok\r\n", 14)        = 14
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 999524})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "RCPT To:<brad>\r\nDATA\r\n", 4096) = 22
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
fcntl64(6, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
fstat64(6, {st_mode=S_IFREG|0600, st_size=22204, ...}) = 0
stat64("/var/lib/imap/mailboxes.db", {st_mode=S_IFREG|0600, st_size=22204, ...}) = 0
fcntl64(6, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "550-Mailbox unknown.  Either the"..., 174) = 174
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 999612})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "RSET\r\n", 4096)               = 6
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "250 2.0.0 ok SESSIONID=<cyrus-10"..., 51) = 51
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 946078})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "RSET\r\n", 4096)               = 6
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "250 2.0.0 ok SESSIONID=<cyrus-10"..., 51) = 51
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 999994})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "MAIL From:<> SIZE=2701\r\n", 4096) = 24
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "250 2.1.0 ok\r\n", 14)        = 14
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 999927})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "RCPT To:<brad>\r\nDATA\r\n", 4096) = 22
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
fcntl64(6, F_SETLKW, {type=F_RDLCK, whence=SEEK_SET, start=0, len=0}) = 0
fstat64(6, {st_mode=S_IFREG|0600, st_size=22204, ...}) = 0
stat64("/var/lib/imap/mailboxes.db", {st_mode=S_IFREG|0600, st_size=22204, ...}) = 0
fcntl64(6, F_SETLKW, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "550-Mailbox unknown.  Either the"..., 174) = 174
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 999987})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "RSET\r\n", 4096)               = 6
open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT (No such file or directory)
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {0, 0})      = 0 (Timeout)
write(1, "250 2.0.0 ok SESSIONID=<cyrus-10"..., 51) = 51
time(NULL)                              = 1543588732
select(1, [0], NULL, NULL, {360, 0})    = 1 (in [0], left {359, 871969})
time(NULL)                              = 1543588732
time(NULL)                              = 1543588732
read(0, "QUIT\r\n", 4096)               = 6
write(1, "221 2.0.0 bye\r\n", 15)       = 15
open("/dev/null", O_RDWR)               = 11
shutdown(0, SHUT_RD)                    = 0
dup2(11, 0)                             = 0
shutdown(1, SHUT_RD)                    = 0
dup2(11, 1)                             = 1
shutdown(2, SHUT_RD)                    = 0
dup2(11, 2)                             = 2
close(11)                               = 0
write(3, "\1\0\0\0\242'\0\0", 8)        = 8
rt_sigaction(SIGALRM, {0x80113f00, [], SA_RESETHAND}, NULL, 8) = 0
rt_sigaction(SIGQUIT, {0x80113f00, [], SA_RESETHAND}, NULL, 8) = 0
rt_sigaction(SIGHUP, {0x80113f00, [], SA_RESTART|SA_RESETHAND}, NULL, 8) = 0
rt_sigaction(SIGINT, {0x80113f00, [], SA_RESTART|SA_RESETHAND}, NULL, 8) = 0
alarm(74)                               = 0
fcntl64(10, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGALRM {si_signo=SIGALRM, si_code=SI_KERNEL, si_value={int=1698768, ptr=0x19ebd0}} ---
sigreturn() (mask [])                   = -1 EINTR (Interrupted system call)
munmap(0xb7700000, 16384)               = 0
close(5)                                = 0
munmap(0xb76f8000, 32768)               = 0
close(6)                                = 0
munmap(0xb76f4000, 16384)               = 0
close(7)                                = 0
munmap(0xb76f0000, 16384)               = 0
close(8)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++

I don't understand the above! Except there are a number of lines like:

open("/var/lib/imap/log/postman/lmtpunix-10146", O_WRONLY|O_CREAT|O_APPEND, 0644) = -1 ENOENT (No such file or directory)

Does any of the above explain 'User unknown', apart from fact that lmtp quit with SIGALRM

 I created /var/lib/imap/log/postman then when the test email is sent /var/lib/imap/log/postman contains this message:

---------- postman Fri Nov 30 15:04:47 2018

>1543590287>220 dell2600-1.bradcan.homelinux.com Cyrus LMTP v2.4.17-Invoca-RPM-2.4.17-7.el6 server ready
<1543590287<LHLO bradcan.homelinux.com
>1543590287>250-dell2600-1.bradcan.homelinux.com
250-8BITMIME
250-ENHANCEDSTATUSCODES
250-PIPELINING
250-SIZE
250-AUTH EXTERNAL
250 IGNOREQUOTA
<1543590287<MAIL From:<brad@xxxxxxxxxxxxxxxxxxxxx> SIZE=653
>1543590287>250 2.1.0 ok
<1543590287<RCPT To:<brad>
DATA
>1543590287>550-Mailbox unknown.  Either there is no mailbox associated with this
550-name or you do not have authorization to see it.
550 5.1.1 User unknown
...

Now I'm guessing, since user brad@xxxxxxxxxxxxxxxxxxxxx does exist and is working then it must be authorization.

So why is authorization failing after years of working? How do I test authorization?








Thanks for your patience.


Cheers
----
Cyrus Home Page: http://www.cyrusimap.org/
List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
To Unsubscribe:
https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
----
Cyrus Home Page: http://www.cyrusimap.org/
List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
To Unsubscribe:
https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus



----
Cyrus Home Page: http://www.cyrusimap.org/
List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
To Unsubscribe:
https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus
----
Cyrus Home Page: http://www.cyrusimap.org/
List Archives/Info: http://lists.andrew.cmu.edu/pipermail/info-cyrus/
To Unsubscribe:
https://lists.andrew.cmu.edu/mailman/listinfo/info-cyrus

[Index of Archives]     [Cyrus SASL]     [Squirrel Mail]     [Asterisk PBX]     [Video For Linux]     [Photo]     [Yosemite News]     [gtk]     [KDE]     [Gimp on Windows]     [Steve's Art]

  Powered by Linux