BUG: Unknown command in userdb socket: CPID?2625

Aki Tuomi aki.tuomi at dovecot.fi
Mon Mar 26 15:05:28 EEST 2018 

Nothing definitive. It's just that the socket expects certain type of
input, this is comparable of trying to configure postfix to speak to
imap-master socket. There is no reason why it should work.

Aki


On 26.03.2018 15:03, Vladimir Tiukhtin wrote:
>
> Hi
>
> And why it is not working with that name? Do you have any document
> describing "special" names? Thanks
>
> Vladimir
>
>
> On 26/03/18 13:02, Aki Tuomi wrote:
>>
>> 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/bb211538/attachment-0001.html>

More information about the dovecot mailing list