BUG: Unknown command in userdb socket: CPID?2625

[Aki Tuomi]

Dovecot has some special socket names, auth-userdb is one of those.

Aki


On 26.03.2018 14:47, Vladimir Tiukhtin wrote:
>
> 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/779ac2f8/attachment-0001.html>