dovecot - Apr 2016 - Broken pipe with own dict server. Timing issue?

Hi,

I have created my own dict server (proxy:[<dict path>]:<destination
dict>) to access a proprietary database. The dict server basically
creates a listing socket on a separate thread and then waits for
incoming requests with accept(handle, NULL, 0). When a request comes in
(i.e., when accept returns the accepted socket fd), the request is
handed over to a handler thread (from a thread pool). The handler thread
then read from the input.

The issue that I have is that if the read is done too fast after the
accept, Dovecot reports a broken pipe:

dovecot: auth-worker(19904): Error:
write(/usr/share/test-server/tmp/test-dict) failed: Broken pipe

This happens for almost all processes that try to access the dict server.

However If I add some sort of delay between the accept call and read
(for example a sleep), everything works. No broken pipe even after
testing with a large number of parallel requests for a long time.
Somehow it looks like if the first read is done too fast, it takes a
long time to read the data. During this time it looks like all other
Dovecot processes are no longer able to connect and report the broken
pipe. With the artificial delay, everything works ok and I can see that
multiple incoming request are handled by multiple threads so it looks
like Dovecot uses multiple auth worker processes. If however one
connection hangs on the read it looks like no Dovecot proccess is able
to connect

Any idea what might be causing the broken pipe in relation to timing of
the read?

Kind regards,

Martijn

On 08 Apr 2016, at 11:08, martijn.list <martijn.list at gmail.com>
wrote:
> 
> Hi,
> 
> I have created my own dict server (proxy:[<dict
path>]:<destination
> dict>) to access a proprietary database. The dict server basically
> creates a listing socket on a separate thread and then waits for
> incoming requests with accept(handle, NULL, 0). When a request comes in
> (i.e., when accept returns the accepted socket fd), the request is
> handed over to a handler thread (from a thread pool). The handler thread
> then read from the input.
> 
> The issue that I have is that if the read is done too fast after the
> accept, Dovecot reports a broken pipe:
> 
> dovecot: auth-worker(19904): Error:
> write(/usr/share/test-server/tmp/test-dict) failed: Broken pipe
That doesn't make much sense.. Broken pipe means that the other side
disconnected the socket. A read wouldn't disconnect a socket no matter when
it was done. I'd say that some bug in your code is causing the socket to be
disconnected too early. stracing it might be helpful.

Oh, and apparently I remembered wrong and the passdb/userdb dict lookups are
done via auth-workers, so you'd be getting a connection from each
auth-worker. It would be just one connection per auth-worker process though. But
they're disconnecting immediately after having finished the pending lookups.

On 04/08/2016 10:38 AM, Timo Sirainen wrote:
> On 08 Apr 2016, at 11:08, martijn.list <martijn.list at gmail.com>
> wrote:
>> 
>> Hi,
>> 
>> I have created my own dict server (proxy:[<dict
>> path>]:<destination dict>) to access a proprietary database.
The
>> dict server basically creates a listing socket on a separate thread
>> and then waits for incoming requests with accept(handle, NULL, 0).
>> When a request comes in (i.e., when accept returns the accepted
>> socket fd), the request is handed over to a handler thread (from a
>> thread pool). The handler thread then read from the input.
>> 
>> The issue that I have is that if the read is done too fast after
>> the accept, Dovecot reports a broken pipe:
>> 
>> dovecot: auth-worker(19904): Error: 
>> write(/usr/share/test-server/tmp/test-dict) failed: Broken pipe
> 
> That doesn't make much sense.. Broken pipe means that the other side
> disconnected the socket. A read wouldn't disconnect a socket no
> matter when it was done. I'd say that some bug in your code is
> causing the socket to be disconnected too early. stracing it might be
> helpful.
Yes my bad ... That's why I always assume the bugs are in my own code ;)

It turned out that the hello message was not always send in the same
packet as the next line. Which is understandable. However it's not
directly clear to me when you can assume that all data has been sent. Am
I right to assume that there are always two lines which end with a newline?

Example:

H2\t0\t0\tname-of-pipe\nLshared/userdb/martijn.list at gmail.com\n

In other words can my service stop reading when two lines are received
and close the connection?

It looks like there is not some sort of "END OF DATA" command.
> Oh, and apparently I remembered wrong and the passdb/userdb dict
> lookups are done via auth-workers, so you'd be getting a connection
> from each auth-worker. It would be just one connection per
> auth-worker process though. But they're disconnecting immediately
> after having finished the pending lookups.
Yes I can confirm this. I added some really long delays to slow down the
dict handling and multiple connections were established.

Kind regards,

Martijn