Hi guys.
I am getting strange error:
BUG: Unknown command in userdb socket: CPID?2625
I am using service auth? to authenticate users on postfix.
*My OS*:
# cat /etc/os-release
NAME="CentOS Linux"
VERSION="7 (Core)"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="7"
PRETTY_NAME="CentOS Linux 7 (Core)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:7"
HOME_URL="https://www.centos.org/"
BUG_REPORT_URL="https://bugs.centos.org/"
CENTOS_MANTISBT_PROJECT="CentOS-7"
CENTOS_MANTISBT_PROJECT_VERSION="7"
REDHAT_SUPPORT_PRODUCT="centos"
REDHAT_SUPPORT_PRODUCT_VERSION="
*My dovecot:*
# dovecot --version
2.2.10
*My config*:
service auth {
? unix_listener auth-userdb {
??? mode = 0600
??? user = postfix
??? group = postfix
? }
}
*My Postfix:*
# rpm -qa | grep postf
postfix-2.10.1-6.el7.x86_64
*Log*:
Mar 25 16:52:33 mail-server postfix/smtpd[2625]: connect from
unknown[10.254.200.202]
Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Loading modules
from directory: /usr/lib64/dovecot/auth
Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_mysql.so
Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_sqlite.so
Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Read auth token
secret from /var/run/dovecot//auth-token-secret.dat
Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: master in:
CPID??????? 2625
Mar 25 16:52:33 mail-server dovecot[2621]: auth: Error: BUG: Unknown
command in userdb socket: CPID?2625
Mar 25 16:52:33 mail-server postfix/smtpd[2625]: fatal: no SASL
authentication mechanisms
Mar 25 16:52:34 mail-server postfix/master[2424]: warning: process
/usr/libexec/postfix/smtpd pid 2625 exit status 1
Mar 25 16:52:34 mail-server postfix/master[2424]: warning:
/usr/libexec/postfix/smtpd: bad command startup -- throttling
The interesting thing is IF I am taking off "-" (minus) from the
socket
name, everything works just perfect! So if I change config to:
service auth {
? unix_listener blabla {
??? mode = 0600
??? user = postfix
??? group = postfix
? }
}
Mar 25 16:55:12 mail-server postfix/smtpd[2872]: connect from
unknown[10.254.200.202]
Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Loading modules
from directory: /usr/lib64/dovecot/auth
Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_mysql.so
Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Module loaded:
/usr/lib64/dovecot/auth/libdriver_sqlite.so
Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Read auth token
secret from /var/run/dovecot//auth-token-secret.dat
Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: auth client
connected (pid=0)
Mar 25 16:55:13 mail-server dovecot[2786]: auth: Debug: client in:
AUTH??????? 1??????? PLAIN??????? service=smtp nologin???????
lip=192.168.101.24??????? rip=10.254.200.202 secured??????? resp=<hidden>
Mar 25 16:55:13 mail-server dovecot[2786]: auth: Debug:
cache(admin at asergis.com,10.254.200.202): miss
Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug:
Loading modules from directory: /usr/lib64/dovecot/auth
Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug:
Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so
Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug:
Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so
Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug:
sql(admin at asergis.com,10.254.200.202): query: SELECT userid AS username,
domain, password FROM users WHERE userid = 'admin' AND domain =
'asergis.com'
Mar 25 16:55:13 mail-server dovecot[2786]: auth: Debug: client passdb
out: OK??????? 1??????? user=admin at asergis.com
Mar 25 16:55:13 mail-server postfix/smtpd[2872]: 5C63030208:
client=unknown[10.254.200.202], sasl_method=PLAIN,
sasl_username=admin at asergis.com
Mar 25 16:55:13 mail-server postfix/cleanup[2881]: 5C63030208:
message-id=<d7706aa7-a2ad-6890-5590-e6f83b5ec3af at asergis.com>
Mar 25 16:55:13 mail-server postfix/qmgr[2870]: 5C63030208:
from=<admin at asergis.com>, size=622, nrcpt=1 (queue active)
P.s. I don't mind to use socket without minus on its name. But this
looks really strange. Thanks. You are awesome
Vladimir
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://dovecot.org/pipermail/dovecot/attachments/20180325/4d63448b/attachment.html>
Did you tell postfix it's talking to dovecot? Aki On 25.03.2018 20:29, Vladimir Tiukhtin wrote:> > Hi guys. > > I am getting strange error: > > > BUG: Unknown command in userdb socket: CPID?2625 > > > I am using service auth? to authenticate users on postfix. > > *My OS*: > > # cat /etc/os-release > NAME="CentOS Linux" > VERSION="7 (Core)" > ID="centos" > ID_LIKE="rhel fedora" > VERSION_ID="7" > PRETTY_NAME="CentOS Linux 7 (Core)" > ANSI_COLOR="0;31" > CPE_NAME="cpe:/o:centos:centos:7" > HOME_URL="https://www.centos.org/" > BUG_REPORT_URL="https://bugs.centos.org/" > > CENTOS_MANTISBT_PROJECT="CentOS-7" > CENTOS_MANTISBT_PROJECT_VERSION="7" > REDHAT_SUPPORT_PRODUCT="centos" > REDHAT_SUPPORT_PRODUCT_VERSION=" > > *My dovecot:* > > # dovecot --version > 2.2.10 > > *My config*: > > service auth { > ? unix_listener auth-userdb { > ??? mode = 0600 > ??? user = postfix > ??? group = postfix > ? } > } > > *My Postfix:* > > # rpm -qa | grep postf > postfix-2.10.1-6.el7.x86_64 > > *Log*: > > Mar 25 16:52:33 mail-server postfix/smtpd[2625]: connect from > unknown[10.254.200.202] > Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Loading > modules from directory: /usr/lib64/dovecot/auth > Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libdriver_mysql.so > Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libdriver_sqlite.so > Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Read auth > token secret from /var/run/dovecot//auth-token-secret.dat > Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: master in: > CPID??????? 2625 > Mar 25 16:52:33 mail-server dovecot[2621]: auth: Error: BUG: Unknown > command in userdb socket: CPID?2625 > Mar 25 16:52:33 mail-server postfix/smtpd[2625]: fatal: no SASL > authentication mechanisms > Mar 25 16:52:34 mail-server postfix/master[2424]: warning: process > /usr/libexec/postfix/smtpd pid 2625 exit status 1 > Mar 25 16:52:34 mail-server postfix/master[2424]: warning: > /usr/libexec/postfix/smtpd: bad command startup -- throttling > > The interesting thing is IF I am taking off "-" (minus) from the > socket name, everything works just perfect! So if I change config to: > > service auth { > ? unix_listener blabla { > ??? mode = 0600 > ??? user = postfix > ??? group = postfix > ? } > } > > Mar 25 16:55:12 mail-server postfix/smtpd[2872]: connect from > unknown[10.254.200.202] > Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Loading > modules from directory: /usr/lib64/dovecot/auth > Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libdriver_mysql.so > Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Module loaded: > /usr/lib64/dovecot/auth/libdriver_sqlite.so > Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Read auth > token secret from /var/run/dovecot//auth-token-secret.dat > Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: auth client > connected (pid=0) > Mar 25 16:55:13 mail-server dovecot[2786]: auth: Debug: client in: > AUTH??????? 1??????? PLAIN??????? service=smtp??????? nologin??????? > lip=192.168.101.24??????? rip=10.254.200.202??????? secured??????? > resp=<hidden> > Mar 25 16:55:13 mail-server dovecot[2786]: auth: Debug: > cache(admin at asergis.com,10.254.200.202): miss > Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug: > Loading modules from directory: /usr/lib64/dovecot/auth > Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug: > Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so > Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug: > Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so > Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug: > sql(admin at asergis.com,10.254.200.202): query: SELECT userid AS > username, domain, password FROM users WHERE userid = 'admin' AND > domain = 'asergis.com' > Mar 25 16:55:13 mail-server dovecot[2786]: auth: Debug: client passdb > out: OK??????? 1??????? user=admin at asergis.com > Mar 25 16:55:13 mail-server postfix/smtpd[2872]: 5C63030208: > client=unknown[10.254.200.202], sasl_method=PLAIN, > sasl_username=admin at asergis.com > Mar 25 16:55:13 mail-server postfix/cleanup[2881]: 5C63030208: > message-id=<d7706aa7-a2ad-6890-5590-e6f83b5ec3af at asergis.com> > Mar 25 16:55:13 mail-server postfix/qmgr[2870]: 5C63030208: > from=<admin at asergis.com>, size=622, nrcpt=1 (queue active) > > > P.s. I don't mind to use socket without minus on its name. But this > looks really strange. Thanks. You are awesome > > > Vladimir >-------------- next part -------------- An HTML attachment was scrubbed... URL: <https://dovecot.org/pipermail/dovecot/attachments/20180326/b3513a79/attachment-0001.html>
Hello Yes, please find my postfix config: smtpd_sasl_type = dovecot #smtpd_sasl_path = /var/run/dovecot/auth smtpd_sasl_path = /var/run/dovecot/auth-userdb smtpd_sasl_auth_enable = yes smtpd_relay_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination As I mentioned if I remove minus from socket name everything works perfect. Thanks Vladimir On 26/03/18 08:37, Aki Tuomi wrote:> > Did you tell postfix it's talking to dovecot? > > Aki > > > On 25.03.2018 20:29, Vladimir Tiukhtin wrote: >> >> Hi guys. >> >> I am getting strange error: >> >> >> BUG: Unknown command in userdb socket: CPID?2625 >> >> >> I am using service auth? to authenticate users on postfix. >> >> *My OS*: >> >> # cat /etc/os-release >> NAME="CentOS Linux" >> VERSION="7 (Core)" >> ID="centos" >> ID_LIKE="rhel fedora" >> VERSION_ID="7" >> PRETTY_NAME="CentOS Linux 7 (Core)" >> ANSI_COLOR="0;31" >> CPE_NAME="cpe:/o:centos:centos:7" >> HOME_URL="https://www.centos.org/" >> BUG_REPORT_URL="https://bugs.centos.org/" >> >> CENTOS_MANTISBT_PROJECT="CentOS-7" >> CENTOS_MANTISBT_PROJECT_VERSION="7" >> REDHAT_SUPPORT_PRODUCT="centos" >> REDHAT_SUPPORT_PRODUCT_VERSION=" >> >> *My dovecot:* >> >> # dovecot --version >> 2.2.10 >> >> *My config*: >> >> service auth { >> ? unix_listener auth-userdb { >> ??? mode = 0600 >> ??? user = postfix >> ??? group = postfix >> ? } >> } >> >> *My Postfix:* >> >> # rpm -qa | grep postf >> postfix-2.10.1-6.el7.x86_64 >> >> *Log*: >> >> Mar 25 16:52:33 mail-server postfix/smtpd[2625]: connect from >> unknown[10.254.200.202] >> Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Loading >> modules from directory: /usr/lib64/dovecot/auth >> Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Module >> loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so >> Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Module >> loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so >> Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: Read auth >> token secret from /var/run/dovecot//auth-token-secret.dat >> Mar 25 16:52:33 mail-server dovecot[2621]: auth: Debug: master in: >> CPID??????? 2625 >> Mar 25 16:52:33 mail-server dovecot[2621]: auth: Error: BUG: Unknown >> command in userdb socket: CPID?2625 >> Mar 25 16:52:33 mail-server postfix/smtpd[2625]: fatal: no SASL >> authentication mechanisms >> Mar 25 16:52:34 mail-server postfix/master[2424]: warning: process >> /usr/libexec/postfix/smtpd pid 2625 exit status 1 >> Mar 25 16:52:34 mail-server postfix/master[2424]: warning: >> /usr/libexec/postfix/smtpd: bad command startup -- throttling >> >> The interesting thing is IF I am taking off "-" (minus) from the >> socket name, everything works just perfect! So if I change config to: >> >> service auth { >> ? unix_listener blabla { >> ??? mode = 0600 >> ??? user = postfix >> ??? group = postfix >> ? } >> } >> >> Mar 25 16:55:12 mail-server postfix/smtpd[2872]: connect from >> unknown[10.254.200.202] >> Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Loading >> modules from directory: /usr/lib64/dovecot/auth >> Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Module >> loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so >> Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Module >> loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so >> Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: Read auth >> token secret from /var/run/dovecot//auth-token-secret.dat >> Mar 25 16:55:12 mail-server dovecot[2786]: auth: Debug: auth client >> connected (pid=0) >> Mar 25 16:55:13 mail-server dovecot[2786]: auth: Debug: client in: >> AUTH??????? 1??????? PLAIN??????? service=smtp nologin??????? >> lip=192.168.101.24 rip=10.254.200.202??????? secured??????? resp=<hidden> >> Mar 25 16:55:13 mail-server dovecot[2786]: auth: Debug: >> cache(admin at asergis.com,10.254.200.202): miss >> Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug: >> Loading modules from directory: /usr/lib64/dovecot/auth >> Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug: >> Module loaded: /usr/lib64/dovecot/auth/libdriver_mysql.so >> Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug: >> Module loaded: /usr/lib64/dovecot/auth/libdriver_sqlite.so >> Mar 25 16:55:13 mail-server dovecot[2786]: auth-worker(2878): Debug: >> sql(admin at asergis.com,10.254.200.202): query: SELECT userid AS >> username, domain, password FROM users WHERE userid = 'admin' AND >> domain = 'asergis.com' >> Mar 25 16:55:13 mail-server dovecot[2786]: auth: Debug: client passdb >> out: OK??????? 1 user=admin at asergis.com >> Mar 25 16:55:13 mail-server postfix/smtpd[2872]: 5C63030208: >> client=unknown[10.254.200.202], sasl_method=PLAIN, >> sasl_username=admin at asergis.com >> Mar 25 16:55:13 mail-server postfix/cleanup[2881]: 5C63030208: >> message-id=<d7706aa7-a2ad-6890-5590-e6f83b5ec3af at asergis.com> >> Mar 25 16:55:13 mail-server postfix/qmgr[2870]: 5C63030208: >> from=<admin at asergis.com>, size=622, nrcpt=1 (queue active) >> >> >> P.s. I don't mind to use socket without minus on its name. But this >> looks really strange. Thanks. You are awesome >> >> >> Vladimir >> >-------------- next part -------------- An HTML attachment was scrubbed... URL: <https://dovecot.org/pipermail/dovecot/attachments/20180326/0e76452f/attachment.html>