BUG: Unknown command in userdb socket: CPID?2625

[Vladimir Tiukhtin]

Hi

What you have suggested works.

service auth {
    unix_listener /var/spool/postfix/private/auth {
          user = postfix
          group = postfix
          mode = 0600
   }
}

This works as well:

service auth {
    unix_listener /var/run/dovecot/auth {
          owner = postfix
          group = postfix
          mode = 0600
   }
}

And this works as well:

service auth {
    unix_listener /var/run/dovecot/auth-test-test {
          owner = postfix
          group = postfix
          mode = 0600
   }
}

And only when socket has name "auth-userdb"

service auth {
    unix_listener auth-userdb {
          owner = postfix
          group = postfix
          mode = 0600
   }
}

it doesn't.

When socket name is "auth-userdb" I can see in the log:

Mar 26 11:43:59 mail-server postfix/smtpd[3648]: connect from 
unknown[10.15.5.127]
Mar 26 11:43:59 mail-server dovecot[3577]: auth: Debug: Loading modules 
from directory: /usr/lib64/dovecot/auth
Mar 26 11:43:59 mail-server dovecot[3577]: auth: Debug: Module loaded: 
/usr/lib64/dovecot/auth/libdriver_mysql.so
Mar 26 11:43:59 mail-server dovecot[3577]: auth: Debug: Module loaded: 
/usr/lib64/dovecot/auth/libdriver_sqlite.so
Mar 26 11:43:59 mail-server dovecot[3577]: auth: Debug: Wrote new auth 
token secret to /var/run/dovecot//auth-token-secret.dat
Mar 26 11:43:59 mail-server postfix/smtpd[3648]: fatal: no SASL 
authentication mechanisms
Mar 26 11:43:59 mail-server dovecot[3577]: auth: Debug: master in: 
CPID        3648
Mar 26 11:43:59 mail-server dovecot[3577]: auth: Error: BUG: Unknown 
command in userdb socket: CPID?3648
Mar 26 11:44:00 mail-server postfix/master[3644]: warning: process 
/usr/libexec/postfix/smtpd pid 3648 exit status 1
Mar 26 11:44:00 mail-server postfix/master[3644]: warning: 
/usr/libexec/postfix/smtpd: bad command startup -- throttling

Vladimir

On 26/03/18 09:55, Aki Tuomi wrote:
> Ah i see.
>
> try this:
>
> dovecot.conf:
>
> service auth {
>    unix_listener /var/spool/postfix/private/auth {
>          owner = postfix
>          group = postfix
>          mode = 0600
>   }
> }
>
> postfix.conf:
>
> smtpd_sasl_path = private/auth
>
> Aki
>
> On 26.03.2018 11:25, Vladimir Tiukhtin wrote:
>>
>> 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/859efcd6/attachment.html>