Mvp fixes

slink commented

2021-04-20 18:05:30 +00:00

(Migrated from code.uplex.de)

A set of fixes to make the primary sponsor's MVP work

geoff commented

2021-04-20 18:07:40 +00:00

(Migrated from code.uplex.de)

assigned to @geoff

slink commented

2021-04-20 18:39:58 +00:00

(Migrated from code.uplex.de)

added 7 commits

63843ecb - 1 commit from branch master
f64bdd40 - We may or may not have an objcore
71281335 - The stdin filedescriptor needs to be non-blocking
2b1c5d9a - No need to close file descriptors which we dup2() to
ba3d530a - Close all file descriptors for the external program
0b12aa09 - Test two pipe VDPs in a row
e16dc7b0 - Improve VDP_END handling

Compare with previous version

added 7 commits <ul><li>63843ecb - 1 commit from branch <code>master</code></li><li>f64bdd40 - We may or may not have an objcore</li><li>71281335 - The stdin filedescriptor needs to be non-blocking</li><li>2b1c5d9a - No need to close file descriptors which we dup2() to</li><li>ba3d530a - Close all file descriptors for the external program</li><li>0b12aa09 - Test two pipe VDPs in a row</li><li>e16dc7b0 - Improve VDP_END handling</li></ul> [Compare with previous version](https://code.uplex.de/uplex-varnish/libvdfp-pipe/merge_requests/1/diffs?diff_id=63&start_sha=b87b63b010cf98296bf36732e70d0ba3d6d733ba)

geoff commented

2021-04-22 14:34:23 +00:00

(Migrated from code.uplex.de)

I don't follow "Somehow related: - do not wait for the program to close stderr" -- why not? From the look of things, we're no longer reading stderr at all. As indicated by this hunk, and I don't see any stderr output in any of the vtc logs. When I run the coverage target (make -j10 coverage), it shows that none of the code to read stderr is executed (starting at about line 498 of the C source). Further down, we have loop continue on the POLLIN event for stderr.

The docs say that the VDP/(future VFP) reads stderr and writes it to the log. You know how I am, if the docs say something, I consider it an obligation.

I don't remember if we ever discussed capturing stderr as a minimal requirement (it's been a while), but it just seems obvious to me. If someone is using the pipe VDP and it's not working, they need to see the error message, otherwise the problem may be impossible to diagnose.

If we want to leave out stderr altogether, we might as well remove all of the code related it. Then we only have two fd's to deal with. But I think that would be a bad idea.

If for some reason your application has a need to ignore stderr, what if we make that a configurable option? IMO in general (not just for a specific application), a VD/FP like this that makes stderr in accessible isn't "minimally viable".

I don't follow "Somehow related: - do not wait for the program to close stderr" -- why not? From the look of things, we're no longer reading stderr at all. As indicated by this hunk, and I don't see any stderr output in any of the vtc logs. When I run the coverage target (make -j10 coverage), it shows that none of the code to read stderr is executed (starting at about line 498 of the C source). Further down, we have loop continue on the POLLIN event for stderr. The docs say that the VDP/(future VFP) reads stderr and writes it to the log. You know how I am, if the docs say something, I consider it an obligation. I don't remember if we ever discussed capturing stderr as a minimal requirement (it's been a while), but it just seems obvious to me. If someone is using the pipe VDP and it's not working, they need to see the error message, otherwise the problem may be impossible to diagnose. If we want to leave out stderr altogether, we might as well remove *all* of the code related it. Then we only have two fd's to deal with. But I think that would be a bad idea. If for some reason your application has a need to ignore stderr, what if we make that a configurable option? IMO in general (not just for a specific application), a VD/FP like this that makes stderr in accessible isn't "minimally viable".

geoff commented

2021-04-22 14:35:07 +00:00

(Migrated from code.uplex.de)

As mentioned above, this looks to me like we ignore stderr altogether.

geoff commented

2021-04-22 14:36:49 +00:00

(Migrated from code.uplex.de)

On the positive side, I see the point here, this is a good idea.

geoff commented

2021-04-22 14:53:39 +00:00

(Migrated from code.uplex.de)

For my understanding, isn't the point here actually to close all non-std* fd's that were inherited after fork? This happens before execve(), and it's easy to see why we need to do that. In contrast, I'm not quite following the bit in the commit message about the second external program and stdin's write end. %^) Don't interactions with another program like that happen after the execve()? I'm not seeing how we have any influence at this point on what happens to fd's after the newly exec'd process starts.

For my understanding, isn't the point here actually to close all non-std* fd's that were inherited after fork? This happens before execve(), and it's easy to see why we need to do that. In contrast, I'm not quite following the bit in the commit message about the second external program and stdin's write end. %^) Don't interactions with another program like that happen *after* the execve()? I'm not seeing how we have any influence at this point on what happens to fd's after the newly exec'd process starts.

geoff commented

2021-04-22 15:07:02 +00:00

(Migrated from code.uplex.de)

@slink I'm concerned about what seems to be the complete disappearance of stderr; other than that it's all lgtm.

The coverage report (make -j10 coverage) says that these lines (from line 481 in vdfp_pipe.c) are never executed during the tests, after nybtes are returned from read(2):

                        if (nbytes == 0) {
                                if (i == STDOUT_FILENO)
                                        closefd(&fds[STDOUT_FILENO].fd);
                                else
                                        closefd(&fds[STDERR_FILENO].fd);
-                               continue;
                        }

Probably because we're now closing fd's earlier (and maybe because we're skipping over stderr?). It might be worth it to consider whether the 0-byte read can provably never happen and we can safely remove these lines (maybe AN(nbytes) after read(2)).

I wrote down a couple of other questions in the comments, more about my own understanding.

@slink I'm concerned about what seems to be the complete disappearance of stderr; other than that it's all lgtm. The coverage report (make -j10 coverage) says that these lines (from line 481 in vdfp_pipe.c) are never executed during the tests, after `nybtes` are returned from `read(2)`: ``` if (nbytes == 0) { if (i == STDOUT_FILENO) closefd(&fds[STDOUT_FILENO].fd); else closefd(&fds[STDERR_FILENO].fd); - continue; } ``` Probably because we're now closing fd's earlier (and maybe because we're skipping over stderr?). It might be worth it to consider whether the 0-byte read can provably never happen and we can safely remove these lines (maybe AN(nbytes) after read(2)). I wrote down a couple of other questions in the comments, more about my own understanding.

slink commented

2021-04-29 11:02:05 +00:00

(Migrated from code.uplex.de)

On a second external progam would also hold the stdin pipe's write end open. from the commit message:

Before addition of the VSUB_closefrom() this would happen:

let's say in varnishd the pipes to program1 are fds >42, <43 and <44 (> meaning "write end", < "read end")
we fork/exec program2 and it inherits the above because of the missing close
in varnish, we close fd 42 to signal to program1 the end of the data stream.
now program2 will wait indefinitely in a read(0) because the write-end of that pipe is still open in program2

In other words, this prevented a setup with more than two programs in a pipeline to work at all.

On _a second external progam would also hold the stdin pipe's write end open._ from the commit message: Before addition of the `VSUB_closefrom()` this would happen: * let's say in varnishd the pipes to program1 are fds >42, <43 and <44 (> meaning "write end", < "read end") * we fork/exec program2 and it inherits the above because of the missing close * in varnish, we close fd 42 to signal to program1 the end of the data stream. * now program2 will wait indefinitely in a `read(0)` because the write-end of that pipe is still open in program2 In other words, this prevented a setup with more than two programs in a pipeline to work at all.

slink commented

2021-04-29 11:03:52 +00:00

(Migrated from code.uplex.de)

This block checks for POLLHUP on either stdin or stderr.
If we stderr is closed by the peer, we also close stderr, as before.
The change is that if the peer closes stdin, we also close stderr.
This is to ensure that if any tool we start in the pipeline misses to close its stderr, we do not wait for this to happen. In my mind, once we have received all payload, we should be done with the program and not wait for it to close stderr eventually.

The actual read of stderr happens just below this block identical for stdin and stderr, and is unchanged.

I have also added a commit to test that we actually log stderr.

This block checks for POLLHUP on either stdin or stderr. If we stderr is closed by the peer, we also close stderr, as before. The change is that if the peer closes stdin, we also close stderr. This is to ensure that if any tool we start in the pipeline misses to close its stderr, we do not wait for this to happen. In my mind, once we have received all payload, we should be done with the program and not wait for it to close stderr eventually. The actual read of stderr happens just below this block identical for stdin and stderr, and is unchanged. I have also added a commit to test that we actually log stderr.

slink commented

2021-04-29 11:04:06 +00:00

(Migrated from code.uplex.de)

added 1 commit

c462dc54 - Test that we capture stderr

Compare with previous version

added 1 commit <ul><li>c462dc54 - Test that we capture stderr</li></ul> [Compare with previous version](https://code.uplex.de/uplex-varnish/libvdfp-pipe/merge_requests/1/diffs?diff_id=67&start_sha=e16dc7b042dfc06c3963f76686249a03ac5be42a)

slink commented

2021-04-29 11:50:48 +00:00

(Migrated from code.uplex.de)

see next discussion

slink commented

2021-04-29 11:57:25 +00:00

(Migrated from code.uplex.de)

added 1 commit

26fafeb6 - Assert that, for POLLIN received, there actually is data to be read

Compare with previous version

added 1 commit <ul><li>26fafeb6 - Assert that, for POLLIN received, there actually is data to be read</li></ul> [Compare with previous version](https://code.uplex.de/uplex-varnish/libvdfp-pipe/merge_requests/1/diffs?diff_id=68&start_sha=c462dc549814973eb1740064bb435a88a28544c6)

slink commented

2021-04-29 11:57:26 +00:00

(Migrated from code.uplex.de)

Right. I agree that the presence of POLLHUP should be reliable, such that we can assert that whenever we receive a POLLIN, there is data available to read.
I have added a commit to that effect

Right. I agree that the presence of POLLHUP should be reliable, such that we can assert that whenever we receive a POLLIN, there is data available to read. I have added a commit to that effect

slink commented

2021-04-29 12:09:01 +00:00

(Migrated from code.uplex.de)

As discussed 1:1 you convinced me that we should really capture stderr to provide proper diagnosis information.
I will change that commit and force push.

As discussed 1:1 you convinced me that we should really capture stderr to provide proper diagnosis information. I will change that commit and force push.

slink commented

2021-04-29 12:20:11 +00:00

(Migrated from code.uplex.de)

added 3 commits

32258d50 - Improve VDP_END handling
88f9b872 - Test that we capture stderr
684aa039 - Assert that, for POLLIN received, there actually is data to be read

Compare with previous version

added 3 commits <ul><li>32258d50 - Improve VDP_END handling</li><li>88f9b872 - Test that we capture stderr</li><li>684aa039 - Assert that, for POLLIN received, there actually is data to be read</li></ul> [Compare with previous version](https://code.uplex.de/uplex-varnish/libvdfp-pipe/merge_requests/1/diffs?diff_id=69&start_sha=26fafeb66285e00cfcbe18141b16d89a77de2ed7)

slink commented

2021-04-29 12:20:13 +00:00

(Migrated from code.uplex.de)

done, force-pushed

geoff commented

2021-04-29 16:57:40 +00:00

(Migrated from code.uplex.de)

@slink I'm now getting an error in append.vtc:

**   top   === logexpect l1001 -wait
**   l1001 Waiting for logexp
**** dT    3.772
**** l1001 match|       1001 Error           c vdfp_pipe: vdp app1: /home/geoff/Develop/varnish/vmods/libvdfp-pipe/src/./tests/append.sh stderr: append 1 while read
***  l1001 expecting| expect 0 = Error stderr: append 2 while read$
**** l1001 match|       1001 Error           c vdfp_pipe: vdp app2: /home/geoff/Develop/varnish/vmods/libvdfp-pipe/src/./tests/append.sh stderr: append 2 while read
***  l1001 expecting| expect 0 = Error stderr: append 2 while read$
**** l1001 err  |       1001 Error           c vdfp_pipe: vdp app1: /home/geoff/Develop/varnish/vmods/libvdfp-pipe/src/./tests/append.sh stderr: append 1 before final
---- l1001 bad| expectation failed

@slink I'm now getting an error in append.vtc: ``` ** top === logexpect l1001 -wait ** l1001 Waiting for logexp **** dT 3.772 **** l1001 match| 1001 Error c vdfp_pipe: vdp app1: /home/geoff/Develop/varnish/vmods/libvdfp-pipe/src/./tests/append.sh stderr: append 1 while read *** l1001 expecting| expect 0 = Error stderr: append 2 while read$ **** l1001 match| 1001 Error c vdfp_pipe: vdp app2: /home/geoff/Develop/varnish/vmods/libvdfp-pipe/src/./tests/append.sh stderr: append 2 while read *** l1001 expecting| expect 0 = Error stderr: append 2 while read$ **** l1001 err | 1001 Error c vdfp_pipe: vdp app1: /home/geoff/Develop/varnish/vmods/libvdfp-pipe/src/./tests/append.sh stderr: append 1 before final ---- l1001 bad| expectation failed ```

slink commented

2021-05-10 15:54:10 +00:00

(Migrated from code.uplex.de)

added 9 commits

6663055d - 1 commit from branch master
dcc7f1be - We may or may not have an objcore
631443ec - The stdin filedescriptor needs to be non-blocking
937622d9 - No need to close file descriptors which we dup2() to
d1c7d43c - Close all file descriptors for the external program
0ac4b2d4 - Test two pipe VDPs in a row
ae6c25d0 - Improve VDP_END handling
69d0f64a - Test that we capture stderr
cf74f76c - Assert that, for POLLIN received, there actually is data to be read

Compare with previous version

added 9 commits <ul><li>6663055d - 1 commit from branch <code>master</code></li><li>dcc7f1be - We may or may not have an objcore</li><li>631443ec - The stdin filedescriptor needs to be non-blocking</li><li>937622d9 - No need to close file descriptors which we dup2() to</li><li>d1c7d43c - Close all file descriptors for the external program</li><li>0ac4b2d4 - Test two pipe VDPs in a row</li><li>ae6c25d0 - Improve VDP_END handling</li><li>69d0f64a - Test that we capture stderr</li><li>cf74f76c - Assert that, for POLLIN received, there actually is data to be read</li></ul> [Compare with previous version](https://code.uplex.de/uplex-varnish/libvdfp-pipe/merge_requests/1/diffs?diff_id=70&start_sha=684aa039beff3f8b64c16bfa09f1a9ca064cb521)

slink commented

2021-05-10 15:54:25 +00:00

(Migrated from code.uplex.de)

@geoff this should be fixed now. I missed to add tolerance for one possible change in ordering

geoff commented

2021-05-10 18:06:43 +00:00

(Migrated from code.uplex.de)

@slink I'm sorry, but I'm still getting an error, the Error messages in append.vtc are still coming in a different order than what logexpect wants. Will attach append.log

@slink I'm sorry, but I'm still getting an error, the Error messages in append.vtc are still coming in a different order than what logexpect wants. Will attach [append.log](/uploads/07fe68692bceb79644bcd84d57261927/append.log)

slink commented

2021-05-23 14:07:13 +00:00

(Migrated from code.uplex.de)

added 2 commits

b1ec77f9 - Test that we capture stderr
b5f25139 - Assert that, for POLLIN received, there actually is data to be read

Compare with previous version

added 2 commits <ul><li>b1ec77f9 - Test that we capture stderr</li><li>b5f25139 - Assert that, for POLLIN received, there actually is data to be read</li></ul> [Compare with previous version](https://code.uplex.de/uplex-varnish/libvdfp-pipe/merge_requests/1/diffs?diff_id=71&start_sha=cf74f76c3365caf41047aae6395a67b5dad04002)

slink commented

2021-05-23 14:07:25 +00:00

(Migrated from code.uplex.de)

sigh sorry @geoff , same thing again. Any change now?

*sigh* sorry @geoff , same thing again. Any change now?

geoff commented

2021-05-25 15:27:42 +00:00

(Migrated from code.uplex.de)

merged

geoff commented

2021-05-25 15:29:08 +00:00

(Migrated from code.uplex.de)

All green and lgtm now, and merged. Thanks @slink!

Rows
Columns

Mvp fixes #1