Bug-Fix for invalid file descriptor validation and missing timeout in unix socket poll

[alexander-mohr]

The poll timeout was only set for fifo.
TCP connections require this timeout as well.
Poll receives a timeout in milliseconds.
The given paramter was in nanoseconds.
An additional define adds the delay in miliseconds.

Some functions validated file descriptor to be greater 0.
If a process is started without stdin, stdout and stderr
the first file descriptor allocated by the process will be 0.
This also will be the case if the above mentioned file descriptors
will be closed on purpose.
As 0 is a valid fd, some methods had to be changed to reflect this.

The program was tested solely for our own use cases, which might differ from yours.
Licensed under Mozilla Public License Version 2.0

^{Alexander Mohr, [email protected], Daimler TSS GmbH, imprint}

[martin-ejdestig]

The poll timeout was only set for fifo.
TCP connections require this timeout as well.

I am wondering a bit about this. Why is it needed? And I assume you mean UNIX/VSOCK and not TCP sockets...?

(Just happened to notice this pr and thought I would ask, since I added VSOCK support recently. I also change the timeout to be -1 unconditionally in #268 .)

[martin-ejdestig]

Also note that timeout is (500 * 10^(6-3) / 3600)s ~= 138.8h for FIFOs, so effectively might as well have -1. So it is not really needed for FIFO:s either?

[alexander-mohr]

I do mean UNIX/VSOCK. We had an issue on qnx where not setting this timeout would lead to blocking the thread in certain situations which lead to missing logs.
In our local build we actually set the timeout to 500ms instead of the timeout used in this PR.
Probably we should test if this is actually necessary. It might be enough to handle the file descriptors properly.
Nevertheless it might be a good idea to remove the ifdef and handle fifo and UNIX/VSOCK the same way.

[alexander-mohr]

Can we make sure that a poll is returning if a connection is gone on all supported systems like qnx and linux or is it better to set a reasonable timeout for example for 1s to make sure this always returns?

[martin-ejdestig]

Hum, I wonder what could make it "block" here and lead to missing messages. Messages are all received on the fd that is poll():ed? If fd is closed in other thread poll() should return?

I noticed #253 a while back. Perhaps there is a race here and the wrong fd ends up being polled?

[alexander-mohr]

I've changed the timeout to 1s for now. I'm trying to find out if we can omit this timeout in general. I'll get back to as soon as I know more.

[alexander-mohr]

Let's assume the following scenario:
OS: QNX
At startup many applications will start before the dlt-daemon and start logging.
After the daemon is ready these applications will start writing theier local ring buffer into the dlt-daemon.
This creates a high load situation in the dlt-daemon.
In some cases an application is blocking in the poll and not returning.
Therefore the local ring buffer is never flushed and transmitted to the daemon.

Setting this timeout makes sure we always exit from this method and retry after the sleep in the housekeeper thread for example.
I was not able to debug this issue to get to the root cause of this lock up as it only happens in some special cases.
Especially is was not able to reproduce this at all on linux so it might be something that only happens on QNX.

What's your argument to omit this timeout?

[ssugiura]

@alexander-mohr @martin-ejdestig I assume you're correct; some timeout value needs to be set on poll.
There are mainly two things we need to handle in housekeeper thread; (1) handle log message from daemon (dlt_user_log_check_user_message), and (2) send messages which are stored in library internal buffer (dlt_user_log_resend_buffer).
As currently poll timeout is set to -1, it will be stuck in first handling, because we won't receive messages from daemon so frequently.
At the time we changed the value to -1, we wanted to reduce CPU usage of the library, but turned out to be wrong.
Triggered from this PR, we are currently doing performance measurement to come up with suitable timeout. In my person opinion, 1sec is too much, as we also have nanosleep in housekeeperthread_function, means next call will come up at maximum 1.5sec later.
We will get back to you soon if it's okay for you.

[alexander-mohr]

Sounds great. We are also using a timeout of 500ms which seems kind of reasonable. But it's great that you are doing measurements to find the correct timeout.
Thanks!

[martin-ejdestig]

Ah, dlt_user_log_resend_buffer() will not be called if poll() is not passed a timeout. I did not notice that. Agreed, a timeout to poll() that is not ~138 hours or -1 makes sense. :)

[ssugiura]

@alexander-mohr After our performance measurement, I suppose setting to 500msec looks good. So prefer the changes you made before to use DLT_USER_RECEIVE_MDELAY. If you agree, can you update as such? Thanks.

[alexmohr]

@alexander-mohr After our performance measurement, I suppose setting to 500msec looks good. So prefer the changes you made before to use DLT_USER_RECEIVE_MDELAY. If you agree, can you update as such? Thanks.

I've changed the code accordingly. Sorry for the late reply due to Christmas and new year.

[ssugiura]

The changes were merged to master branch manually. Closing this PR.
Thanks @alexander-mohr for the fix!