failed: read(/var/run/dovecot/dns-client)

[Aki Tuomi]

On 11.4.2019 11.11, Laura Smith via dovecot wrote:
> ‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
> On Thursday, April 11, 2019 9:05 AM, Aki Tuomi <aki.tuomi at open-xchange.com> wrote:
>
>>> On 11 April 2019 11:02 Laura Smith via dovecot dovecot at dovecot.org wrote:
>>> ‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
>>> On Thursday, April 11, 2019 12:55 AM, John Fawcett via dovecot dovecot at dovecot.org wrote:
>>>
>>>> On 11/04/2019 00:51, Laura Smith via dovecot wrote:
>>>>
>>>>> ‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
>>>>> On Wednesday, April 10, 2019 11:48 PM, John Fawcett via dovecot dovecot at dovecot.org wrote:
>>>>>
>>>>>> On 11/04/2019 00:18, Laura Smith via dovecot wrote:
>>>>>>
>>>>>>> ‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
>>>>>>> On Wednesday, April 10, 2019 10:24 PM, Aki Tuomi aki.tuomi at open-xchange.com wrote:
>>>>>>>
>>>>>>>>> On 10 April 2019 23:56 Laura Smith via dovecot < dovecot at dovecot.org> wrote:
>>>>>>>>> ‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
>>>>>>>>> On Wednesday, April 10, 2019 9:14 PM, Aki Tuomi < aki.tuomi at open-xchange.com> wrote:
>>>>>>>>>
>>>>>>>>>>> On 10 April 2019 23:13 Laura Smith via dovecot dovecot at dovecot.org wrote:
>>>>>>>>>>> Sent with ProtonMail Secure Email.
>>>>>>>>>>> ‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
>>>>>>>>>>> On Wednesday, April 10, 2019 8:20 PM, Aki Tuomi aki.tuomi at open-xchange.com wrote:
>>>>>>>>>>>
>>>>>>>>>>>>> On 10 April 2019 22:13 Laura Smith via dovecot dovecot at dovecot.org wrote:
>>>>>>>>>>>>> On Wednesday, April 10, 2019 7:57 PM, Aki Tuomi aki.tuomi at open-xchange.com wrote:
>>>>>>>>>>>>>
>>>>>>>>>>>>>>> On 10 April 2019 21:26 Laura Smith via dovecot dovecot at dovecot.org wrote:
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> ==========================================================================
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> dsync( foobar at example.com): Error: imapc(foobar.example.com:993): dns_lookup(foobar.example.com) failed: read(/var/run/dovecot/dns-client) failed: read(size=512) failed: Connection reset by peer
>>>>>>>>>>>>>>> This is dovecot's internal dns-client, and something goes wrong when talking to the service.
>>>>>>>>>>>>>>> dsync( foobar at example.com): Error: Failed to initialize user: imapc: Login to foobar.example.com failed: Disconnected from server
>>>>>>>>>>>>>>> This is btw dsync service, not imap service.
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> ===============================================================================================================================================================================================================================================================================================================================================================================================================================================================================
>>>>>>>>>>>>>>>
>>>>>>>>>>>>>>> Initially I thought "oh no, not another AppArmor block".
>>>>>>>>>>>>>>> But then surely the second message would not appear if the DNS lookup was not successful ?
>>>>>>>>>>>>>>> Also "dig foobar.example.com" works fine.
>>>>>>>>>>>>>>> How should I be troubleshooting this ? And if it is still likely to be AppArmor, what is calling it ? "doveadm" itself or something else ? What does "/var/run/dovecot/dns-client" do and why doesn't dovecot use standard OS calls like everyone else ?
>>>>>>>>>>>>>>> Because the "standard OS call" is blocking and we would prefer it to not block everything else.
>>>>>>>>>>>>>>> So many questions !
>>>>>>>>>>>>>>> Aki
>>>>>>>>>>>>>>> Thanks for your reply, but both those message are generated from a simple :
>>>>>>>>>>>>>>> doveadm -v -o mail_fsync=never backup -R -u foobar at example.com imapc:
>>>>>>>>>>>>>>> So I don't know what you mean about dsync service failing ? Surely the DNS lookup succeeded if the 'dsync service' failed due to remote disconnect ?
>>>>>>>>>>>>>>> I'm still none the wiser as to where to start looking for troubleshoting ?
>>>>>>>>>>>>>>> Did you check dovecot logs? Maybe there is something useful?
>>>>>>>>>>>>>>> Aki
>>>>>>>>>>>>>>> Only the same old cryptic message about dns-client ?
>>>>>>>>>>>>>>> master: Fatal: execv(/usr/lib/dovecot/dns-client) failed: Permission denied
>>>>>>>>>>>>>>> Something prevents executing the dns-client binary.
>>>>>>>>>>>>>>> master: Error: service(dns_client): command startup failed, throttling for 16 secs
>>>>>>>>>>>>>>> dns_client: Fatal: master: service(dns_client): child 14293 returned error 84 (exec() failed)
>>>>>>>>>>>>>>> Aki
>>>>>>>>>>>>>>> Yes but is it being called by doveadm directly or by some other dovecot program ? If I'm going to have to go down the AppArmor route, then I would prefer if you told me what was calling it instead of me having to un-necessarily spend time doing straces !
>>>>>>>>>>>>>>> Also, should I be able to call dns-client directly myself ? (or is there a way to do so to enable testing ?
>>>>>>>>>>>>>>> It is started by dovecot's master process when you connect to dns-client unix socket. You can try
>>>>>>>>>>>>>>> socat stdio unix-connect:/var/run/dovecot/dns-client
>>>>>>>>>>>>>>> I thought apparmor tells when something is blocked into kernel log? have you checked dmesg?
>>>>>>>> Apologies for your frustration.
>>>>>>> Yeah nothing in dmesg.  I'm still hunting around to find some log somewhere but so far silence.
>>>>>>> "socat stdio unix-connect:/var/run/dovecot/dns-client" runs but returns nothing. Is that expected ?
>>>>>>> When you say "dovecot's master process", so  doveadm sync talks to the master process ?  So in terms of apparmor I would therefore be looking at /usr/sbin/dovecot ?  If that's the case, the relevant apparmor permisssions are already provided :
>>>>>>>   /{,var/}run/dovecot/ rw,
>>>>>>>   /{,var/}run/dovecot/** rw,
>>>>>>> Laura
>>>>>> Do the above apparmor settings give permission to dovecot to execute
>>>>>> /usr/lib/dovecot/dns-client, assuming that the user under which dovecot
>>>>>> is running already has file system permissions to do that?
>>>>>> John
>>>>> John,
>>>>> Here's the definitive answer to your question (and anyone else thinking of pointing the finger at apparmor):
>>>>> foo:/home/foo # sudo systemctl stop apparmor
>>>>> foo:/home/foo # doveadm -v -o mail_fsync=never backup -R -u foobar at example.com imapc:
>>>>> dsync(foobar at example.com): Error: imapc(foobar.example.com:993): dns_lookup(foobar.example.com) failed: DNS lookup timed out
>>>>> dsync(foobar at example.com): Error: Failed to initialize user: imapc: Login to foobar.example.com failed: Disconnected from server
>>>>> So. Can we move on from the "blame apparmor" ? ;-)
>>>> Laura
>>>> I'd suggest doing the test with a restart of dovecot in between stopping
>>>> apparmor and running the doveadm command. Check your logs to see if
>>>> there is no longer any message generated about not being able to execv
>>>> /usr/lib/dovecot/dns-client.
>>>> foo:/home/foo # sudo systemctl stop apparmor
>>>> foo:/home/foo # sudo systemctl restart dovecot
>>>> foo:/home/foo # doveadm -v -o mail_fsync=never backup -R -u foobar at example.com imapc:
>>>> John
>>> Same again....
>>> failed: read(/var/run/dovecot/dns-client) failed: read(size=512) failed: Connection reset by peer
>> And your logs probably indicate that same Fatal error that the service cannot be started?
>>
>> Wonder if this is caused by systemd? Can you try also
>>
>> systemctl stop dovecot
>> dovecot -F
>>
>> then try socat and see if it works?
>>
>> Aki
> I get no output om the "dovecot -F" side ? Dovecot launches but no consle output, either at launch or in response to my test commands.
>

Oh sorry. It will log into syslog anyways unless you set
log_path=/dev/stdout in config.


Aki