On 7/3/2020 7:09 AM, Ken Brown via Cygwin wrote:
On 7/2/2020 1:50 PM, Morten Kjærulff via Cygwin wrote:
I think we got a new release around the beginning of June, right?
You said that there were still issues (I can confirm).
If it can help, here is the output I see today of above scripts:
$ ./tp.sh
[...]
0 [fifo_reader] diff 1806 C:\cygwin\bin\diff.exe: *** fatal
error - Can't update my handlers, Win32 error 87
Thanks for the report and the simple test case. Obviously I still have more
work to do on this.
Hi Morten,
I've attempted to fix the bugs (see
https://cygwin.com/pipermail/cygwin-patches/2020q3/010380.html). With these
patches installed, I no longer see a fatal error or hanging diff processes. But
your script still doesn't work as you expect. On a typical run of the parallel
part, 6 or 7 of the 10 diff processes see the FIFO t.pip as empty.
Here's a sample run under strace, so that I could see what was going on. 7 of
the 10 diff processes saw t.pip as empty on this run.
$ strace -o tpip.sh.strace sh -c ./tpip.sh
PID PPID PGID WINPID TTY UID STIME COMMAND
1307 1306 1307 10932 pty1 197609 17:50:12 /usr/bin/bash
18426 1 18426 9360 cons0 197609 06:47:31 /usr/bin/sh
18429 18426 18426 13900 cons0 197609 06:47:32 /usr/bin/ps
1306 1 1306 3768 ? 197609 17:50:11 /usr/bin/mintty
18424 1307 18424 21840 pty1 197609 06:47:31 /usr/bin/strace
result1 start
10
0
0
0
0
0
0
0
0
0
0
result1 end
0a1,2
> line1
> line2
0a1,2
> line1
> line2
0a1,2
> line1
> line2
0a1,2
> line1
> line2
0a1,2
> line1
> line2
0a1,2
0a1,2
> line1
> line1
> line2
> line2
result2 start
10
0
1
1
0
1
1
1
1
1
0
result2 end
PID PPID PGID WINPID TTY UID STIME COMMAND
18480 18430 18426 15580 cons0 197609 06:47:33 /usr/bin/cp
1307 1306 1307 10932 pty1 197609 17:50:12 /usr/bin/bash
18484 18426 18426 21264 cons0 197609 06:47:44 /usr/bin/ps
18430 18426 18426 23472 cons0 197609 06:47:32 /usr/bin/sh
18426 1 18426 9360 cons0 197609 06:47:31 /usr/bin/sh
1306 1 1306 3768 ? 197609 17:50:11 /usr/bin/mintty
18424 1307 18424 21840 pty1 197609 06:47:31 /usr/bin/strace
I'm attaching your script for ease of reference, and I'm attaching an excerpt
from the strace output, to which I've added a few comments. The excerpt shows
all open, close, read, and write system calls involving t.pip.
Here's a summary of what you can see from those system calls in the parallel
part of the script. In what follows, I've called the diff processes diff-1,
diff-2,..., diff-10, and similarly for the cp processes (although there are only
four of them).
1. cp-1 tries to open t.pip for writing and blocks. It unblocks when diff-1
opens t.pip for reading, and both processes run to completion as expected.
2. diff-2, diff-3, diff-4, and diff-5 try to open t.pip for reading, and they
block until cp-2 opens it for writing. Then cp-2 writes 12 bytes to t.pip and
closes it, and the four diff processes all try to read. diff-4 gets there first
and reads the 12 bytes; it reads once more and sees EOF because there is no data
available in the pipe and there are no writers open[1], so it considers those 12
bytes to constitute the file t.pip. It later exits with success.
diff-2, diff-3, and diff-5 all complete their reads before cp-3 opens t.pip.
They see EOF for the same reason as above, so t.pip appears empty and they exit
with failure.
3. diff-6, diff-7, diff-8, diff-9, and diff-10 try to open t.pip for reading,
and they block until cp-3 opens it for writing. Then cp-3 writes 12 bytes to
t.pip and closes it, and the five diff processes all try to read. diff-10 gets
there first and reads 12 bytes followed by EOF; it later exits with success.
diff-6, diff-7, diff-8, and diff-9 all complete their reads before cp-4 opens
t.pip. They see EOF, so t.pip appears empty and they exit with failure.
4. cp-4 tries to open t.pip and blocks because there are no more diff processes.
I've run your script on Linux a few times, and it usually[2] behaves as you
expect, with all diff processes succeeding. For reasons I don't understand, the
diff and cp processes apparently alternate most of the time on Linux, rather
than having 4 or 5 diff processes lumped together between the cp processes as on
Cygwin.
If someone can figure out the reason for the difference, and if it turns out to
be related to the FIFO code, I could try to modify the code to make Cygwin
behave more like Linux.
Ken
[1] From https://pubs.opengroup.org/onlinepubs/9699919799/functions/read.html:
When attempting to read from an empty pipe or FIFO:
* If no process has the pipe open for writing, read() shall return 0 to
indicate end-of-file.
[2] But I did have one Linux run in which one of the ten diff processes saw an
empty t.pip and failed as on Cygwin.
Run diff 10 times sequentially
1. cp 18431 and diff 18433
37 15003 [main] cp 18431 open: open(t.pip, 0x10401)
43 32609 [main] diff 18433 open: open(t.pip, 0x0)
103856 120245 [main] cp 18431 open: 4 = open(t.pip, 0x18401)
74 34419 [main] diff 18433 open: 3 = open(t.pip, 0x8000)
33 120667 [main] cp 18431 write: write(4, 0x800050000, 12)
39 120706 [main] cp 18431 write: 12 = write(4, 0x800050000, 12)
30 120827 [main] cp 18431 close: close(4)
34 120910 [main] cp 18431 close: 0 = close(4)
39 36282 [main] diff 18433 read: read(3, 0x800069FF0, 65536) blocking
31 36378 [main] diff 18433 read: 12 = read(3, 0x800069FF0, 12)
31 36409 [main] diff 18433 read: read(3, 0x800069FFC, 65524) blocking
31 36475 [main] diff 18433 read: 0 = read(3, 0x800069FFC, 0)
621 38274 [main] diff 18433 close: close(3)
118 38392 [main] diff 18433 close: 0 = close(3)
2. diff 18434 and cp 18435
44 32793 [main] diff 18434 open: open(t.pip, 0x0)
18300 34541 [main] cp 18435 open: 4 = open(t.pip, 0x18401)
92 34663 [main] diff 18434 open: 3 = open(t.pip, 0x8000)
33 35126 [main] cp 18435 write: write(4, 0x800050000, 12)
36 35162 [main] cp 18435 write: 12 = write(4, 0x800050000, 12)
34 35296 [main] cp 18435 close: close(4)
35 35382 [main] cp 18435 close: 0 = close(4)
39 36716 [main] diff 18434 read: read(3, 0x800069FF0, 65536) blocking
33 36788 [main] diff 18434 read: 12 = read(3, 0x800069FF0, 12)
33 36821 [main] diff 18434 read: read(3, 0x800069FFC, 65524) blocking
31 36886 [main] diff 18434 read: 0 = read(3, 0x800069FFC, 0)
734 38790 [main] diff 18434 close: close(3)
134 38924 [main] diff 18434 close: 0 = close(3)
3. cp 18436 and diff 18437
41 14772 [main] cp 18436 open: open(t.pip, 0x10401)
44 32185 [main] diff 18437 open: open(t.pip, 0x0)
25768 41893 [main] cp 18436 open: 4 = open(t.pip, 0x18401)
69 34057 [main] diff 18437 open: 3 = open(t.pip, 0x8000)
43 42441 [main] cp 18436 write: write(4, 0x800050000, 12)
46 42487 [main] cp 18436 write: 12 = write(4, 0x800050000, 12)
35 42633 [main] cp 18436 close: close(4)
35 42719 [main] cp 18436 close: 0 = close(4)
36 36061 [main] diff 18437 read: read(3, 0x800069FF0, 65536) blocking
29 36126 [main] diff 18437 read: 12 = read(3, 0x800069FF0, 12)
32 36158 [main] diff 18437 read: read(3, 0x800069FFC, 65524) blocking
30 36225 [main] diff 18437 read: 0 = read(3, 0x800069FFC, 0)
646 38053 [main] diff 18437 close: close(3)
121 38174 [main] diff 18437 close: 0 = close(3)
4. cp 18438 and diff 18439
43 32153 [main] diff 18439 open: open(t.pip, 0x0)
24135 40474 [main] cp 18438 open: 4 = open(t.pip, 0x18401)
77 33806 [main] diff 18439 open: 3 = open(t.pip, 0x8000)
39 40861 [main] cp 18438 write: write(4, 0x800050000, 12)
39 40900 [main] cp 18438 write: 12 = write(4, 0x800050000, 12)
29 41048 [main] cp 18438 close: close(4)
43 41151 [main] cp 18438 close: 0 = close(4)
42 35669 [main] diff 18439 read: read(3, 0x800069FF0, 65536) blocking
30 35729 [main] diff 18439 read: 12 = read(3, 0x800069FF0, 12)
34 35763 [main] diff 18439 read: read(3, 0x800069FFC, 65524) blocking
33 35831 [main] diff 18439 read: 0 = read(3, 0x800069FFC, 0)
623 37617 [main] diff 18439 close: close(3)
123 37740 [main] diff 18439 close: 0 = close(3)
5. cp 18440 and diff 18441
37 15221 [main] cp 18440 open: open(t.pip, 0x10401)
42 31887 [main] diff 18441 open: open(t.pip, 0x0)
24291 40881 [main] cp 18440 open: 4 = open(t.pip, 0x18401)
38 33908 [main] diff 18441 open: 3 = open(t.pip, 0x8000)
41 41256 [main] cp 18440 write: write(4, 0x800050000, 12)
45 41301 [main] cp 18440 write: 12 = write(4, 0x800050000, 12)
36 41445 [main] cp 18440 close: close(4)
37 41531 [main] cp 18440 close: 0 = close(4)
31 35775 [main] diff 18441 read: read(3, 0x800069FF0, 65536) blocking
31 35847 [main] diff 18441 read: 12 = read(3, 0x800069FF0, 12)
30 35877 [main] diff 18441 read: read(3, 0x800069FFC, 65524) blocking
30 35940 [main] diff 18441 read: 0 = read(3, 0x800069FFC, 0)
683 37830 [main] diff 18441 close: close(3)
138 37968 [main] diff 18441 close: 0 = close(3)
6. cp 18442 and diff 18443
35 15099 [main] cp 18442 open: open(t.pip, 0x10401)
42 31183 [main] diff 18443 open: open(t.pip, 0x0)
23245 39624 [main] cp 18442 open: 4 = open(t.pip, 0x18401)
77 32896 [main] diff 18443 open: 3 = open(t.pip, 0x8000)
36 39964 [main] cp 18442 write: write(4, 0x800050000, 12)
37 40001 [main] cp 18442 write: 12 = write(4, 0x800050000, 12)
39 40141 [main] cp 18442 close: close(4)
37 40233 [main] cp 18442 close: 0 = close(4)
39 34681 [main] diff 18443 read: read(3, 0x800069FF0, 65536) blocking
26 34744 [main] diff 18443 read: 12 = read(3, 0x800069FF0, 12)
29 34773 [main] diff 18443 read: read(3, 0x800069FFC, 65524) blocking
31 34839 [main] diff 18443 read: 0 = read(3, 0x800069FFC, 0)
636 36716 [main] diff 18443 close: close(3)
127 36843 [main] diff 18443 close: 0 = close(3)
7. cp 18444 and diff 18445
40 14921 [main] cp 18444 open: open(t.pip, 0x10401)
42 32057 [main] diff 18445 open: open(t.pip, 0x0)
24406 40658 [main] cp 18444 open: 4 = open(t.pip, 0x18401)
77 33776 [main] diff 18445 open: 3 = open(t.pip, 0x8000)
41 41052 [main] cp 18444 write: write(4, 0x800050000, 12)
40 41092 [main] cp 18444 write: 12 = write(4, 0x800050000, 12)
36 41229 [main] cp 18444 close: close(4)
34 41313 [main] cp 18444 close: 0 = close(4)
39 35627 [main] diff 18445 read: read(3, 0x800069FF0, 65536) blocking
31 35695 [main] diff 18445 read: 12 = read(3, 0x800069FF0, 12)
34 35729 [main] diff 18445 read: read(3, 0x800069FFC, 65524) blocking
34 35798 [main] diff 18445 read: 0 = read(3, 0x800069FFC, 0)
641 37591 [main] diff 18445 close: close(3)
119 37710 [main] diff 18445 close: 0 = close(3)
8. cp 18446 and diff 18447
43 14974 [main] cp 18446 open: open(t.pip, 0x10401)
43 31763 [main] diff 18447 open: open(t.pip, 0x0)
24704 41011 [main] cp 18446 open: 4 = open(t.pip, 0x18401)
90 33706 [main] diff 18447 open: 3 = open(t.pip, 0x8000)
33 41543 [main] cp 18446 write: write(4, 0x800050000, 12)
38 41581 [main] cp 18446 write: 12 = write(4, 0x800050000, 12)
29 41714 [main] cp 18446 close: close(4)
34 41793 [main] cp 18446 close: 0 = close(4)
41 35699 [main] diff 18447 read: read(3, 0x800069FF0, 65536) blocking
32 35763 [main] diff 18447 read: 12 = read(3, 0x800069FF0, 12)
34 35797 [main] diff 18447 read: read(3, 0x800069FFC, 65524) blocking
35 35866 [main] diff 18447 read: 0 = read(3, 0x800069FFC, 0)
645 37695 [main] diff 18447 close: close(3)
122 37817 [main] diff 18447 close: 0 = close(3)
9. cp 18448 and diff 18449
49 31604 [main] diff 18449 open: open(t.pip, 0x0)
23502 39928 [main] cp 18448 open: 4 = open(t.pip, 0x18401)
60 33367 [main] diff 18449 open: 3 = open(t.pip, 0x8000)
35 40336 [main] cp 18448 write: write(4, 0x800050000, 12)
36 40372 [main] cp 18448 write: 12 = write(4, 0x800050000, 12)
29 40503 [main] cp 18448 close: close(4)
36 40585 [main] cp 18448 close: 0 = close(4)
37 35212 [main] diff 18449 read: read(3, 0x800069FF0, 65536) blocking
25 35269 [main] diff 18449 read: 12 = read(3, 0x800069FF0, 12)
29 35298 [main] diff 18449 read: read(3, 0x800069FFC, 65524) blocking
30 35357 [main] diff 18449 read: 0 = read(3, 0x800069FFC, 0)
626 37152 [main] diff 18449 close: close(3)
118 37270 [main] diff 18449 close: 0 = close(3)
10. cp 18450 and diff 18451
38 15186 [main] cp 18450 open: open(t.pip, 0x10401)
44 32061 [main] diff 18451 open: open(t.pip, 0x0)
26172 42629 [main] cp 18450 open: 4 = open(t.pip, 0x18401)
34 33628 [main] diff 18451 open: 3 = open(t.pip, 0x8000)
34 42998 [main] cp 18450 write: write(4, 0x800050000, 12)
43 43041 [main] cp 18450 write: 12 = write(4, 0x800050000, 12)
37 43179 [main] cp 18450 close: close(4)
35 43261 [main] cp 18450 close: 0 = close(4)
36 35444 [main] diff 18451 read: read(3, 0x800069FF0, 65536) blocking
30 35511 [main] diff 18451 read: 12 = read(3, 0x800069FF0, 12)
35 35546 [main] diff 18451 read: read(3, 0x800069FFC, 65524) blocking
30 35611 [main] diff 18451 read: 0 = read(3, 0x800069FFC, 0)
696 37539 [main] diff 18451 close: close(3)
159 37698 [main] diff 18451 close: 0 = close(3)
Run diff 10 times in parallel
a. cp 18452 has been blocking for a long time trying to open.
diff 18459 opens; cp 18452 and diff 18459 quickly finish before the
next diff or cp tries to open.
41 19137 [main] cp 18452 open: open(t.pip, 0x10401)
94 55546 [main] diff 18459 open: open(t.pip, 0x0)
351587 372145 [main] cp 18452 open: 4 = open(t.pip, 0x18401)
142 59237 [main] diff 18459 open: 3 = open(t.pip, 0x8000)
114 373531 [main] cp 18452 write: write(4, 0x800050000, 12)
89 373620 [main] cp 18452 write: 12 = write(4, 0x800050000, 12)
104 374064 [main] cp 18452 close: close(4)
85 374284 [main] cp 18452 close: 0 = close(4)
157 66100 [main] diff 18459 read: read(3, 0x800069FF0, 65536) blocking
111 66329 [main] diff 18459 read: 12 = read(3, 0x800069FF0, 12)
90 66419 [main] diff 18459 read: read(3, 0x800069FFC, 65524) blocking
61 66584 [main] diff 18459 read: 0 = read(3, 0x800069FFC, 0)
2233 72260 [main] diff 18459 close: close(3)
262 72522 [main] diff 18459 close: 0 = close(3)
b. diff 18461, 18463, 18465, 18467 try to open.
cp 18472 opens, unblocking the four diffs, which all try to read.
diff 18465 reads successfully, the others see EOF, all before the
next cp tries to open.
[diff 18469 and 18471 try to open after cp 18472 has closed]
141 66485 [main] diff 18461 open: open(t.pip, 0x0)
137 78681 [main] diff 18463 open: open(t.pip, 0x0)
116 83771 [main] diff 18465 open: open(t.pip, 0x0)
141 85018 [main] diff 18467 open: open(t.pip, 0x0)
115 31038 [main] cp 18472 open: open(t.pip, 0x10401)
177 33462 [main] cp 18472 open: 4 = open(t.pip, 0x18401)
74078 157243 [main] diff 18463 open: 3 = open(t.pip, 0x8000)
44063 131988 [main] diff 18465 open: 3 = open(t.pip, 0x8000)
14695 103578 [main] diff 18467 open: 3 = open(t.pip, 0x8000)
55 176955 [main] diff 18461 open: 3 = open(t.pip, 0x8000)
94 34471 [main] cp 18472 write: write(4, 0x800050000, 12)
105 34576 [main] cp 18472 write: 12 = write(4, 0x800050000, 12)
95 34979 [main] cp 18472 close: close(4)
134 35264 [main] cp 18472 close: 0 = close(4)
203 139097 [main] diff 18465 read: read(3, 0x800069FF0, 65536) blocking
212 110708 [main] diff 18467 read: read(3, 0x800069FF0, 65536) blocking
252 164424 [main] diff 18463 read: read(3, 0x800069FF0, 65536) blocking
262 184121 [main] diff 18461 read: read(3, 0x800069FF0, 65536) blocking
[ 109 79383 [main] diff 18469 open: open(t.pip, 0x0)]
97 139800 [main] diff 18465 read: 12 = read(3, 0x800069FF0, 12)
130 139930 [main] diff 18465 read: read(3, 0x800069FFC, 65524) blocking
160 185245 [main] diff 18461 read: 0 = read(3, 0x800069FF0, 0)
176 140799 [main] diff 18465 read: 0 = read(3, 0x800069FFC, 0)
2324 147324 [main] diff 18465 close: close(3)
304 147628 [main] diff 18465 close: 0 = close(3)
916 197811 [main] diff 18461 close: close(3)
177 197988 [main] diff 18461 close: 0 = close(3)
86 181046 [main] diff 18463 read: 0 = read(3, 0x800069FF0, 0)
[ 111 76236 [main] diff 18471 open: open(t.pip, 0x0)]
1247 192785 [main] diff 18463 close: close(3)
344 193129 [main] diff 18463 close: 0 = close(3)
122 143456 [main] diff 18467 read: 0 = read(3, 0x800069FF0, 0)
1066 154923 [main] diff 18467 close: close(3)
291 155214 [main] diff 18467 close: 0 = close(3)
c. diff 18469, 18471 have already tried to open.
Now diffs 18474, 18476, 18477 also try.
cp 18479 opens, unblocking the five diffs, which all try to read.
diff 18477 reads successfully, the others see EOF.
117 75684 [main] diff 18474 open: open(t.pip, 0x0)
57 68789 [main] diff 18476 open: open(t.pip, 0x0)
51 53390 [main] diff 18477 open: open(t.pip, 0x0)
37 14787 [main] cp 18479 open: open(t.pip, 0x10401)
98 16125 [main] cp 18479 open: 4 = open(t.pip, 0x18401)
5873 60930 [main] diff 18477 open: 3 = open(t.pip, 0x8000)
41946 121620 [main] diff 18474 open: 3 = open(t.pip, 0x8000)
23125 93685 [main] diff 18476 open: 3 = open(t.pip, 0x8000)
65628 146078 [main] diff 18471 open: 3 = open(t.pip, 0x8000)
47 175332 [main] diff 18469 open: 3 = open(t.pip, 0x8000)
64 16848 [main] cp 18479 write: write(4, 0x800050000, 12)
86 16934 [main] cp 18479 write: 12 = write(4, 0x800050000, 12)
81 17241 [main] cp 18479 close: close(4)
82 17392 [main] cp 18479 close: 0 = close(4)
72 64964 [main] diff 18477 read: read(3, 0x800069FF0, 65536) blocking
75 125673 [main] diff 18474 read: read(3, 0x800069FF0, 65536) blocking
83 97764 [main] diff 18476 read: read(3, 0x800069FF0, 65536) blocking
78 150184 [main] diff 18471 read: read(3, 0x800069FF0, 65536) blocking
98 179463 [main] diff 18469 read: read(3, 0x800069FF0, 65536) blocking
44 65392 [main] diff 18477 read: 12 = read(3, 0x800069FF0, 12)
74 65466 [main] diff 18477 read: read(3, 0x800069FFC, 65524) blocking
63 150850 [main] diff 18471 read: 0 = read(3, 0x800069FF0, 0)
37 65904 [main] diff 18477 read: 0 = read(3, 0x800069FFC, 0)
761 68071 [main] diff 18477 close: close(3)
183 68254 [main] diff 18477 close: 0 = close(3)
342 155780 [main] diff 18471 close: close(3)
104 155884 [main] diff 18471 close: 0 = close(3)
34 195050 [main] diff 18469 read: 0 = read(3, 0x800069FF0, 0)
354 200567 [main] diff 18469 close: close(3)
220 200787 [main] diff 18469 close: 0 = close(3)
47 129311 [main] diff 18476 read: 0 = read(3, 0x800069FF0, 0)
58 157414 [main] diff 18474 read: 0 = read(3, 0x800069FF0, 0)
529 137014 [main] diff 18476 close: close(3)
161 137175 [main] diff 18476 close: 0 = close(3)
560 165180 [main] diff 18474 close: close(3)
188 165368 [main] diff 18474 close: 0 = close(3)
d. cp 18480 tries to open but blocks because there are no more diff processes.
35 15508 [main] cp 18480 open: open(t.pip, 0x10401)
#!/bin/sh
rm -f t.pip t.txt
mkfifo t.pip
printf "line1\nline2\n" >t.txt
ps
{
while true ; do
cp t.txt t.pip
done
} &
rm -f t.rc.*
for rc in 0 1 2 3 4 5 6 7 8 9 ; do
{
diff t.pip t.txt
echo $? >t.rc.$rc
}
done
echo result1 start
ls t.rc.* | wc -l
cat t.rc.*
echo result1 end
rm -f t.rc.*
for rc in 0 1 2 3 4 5 6 7 8 9 ; do
{
diff t.pip t.txt
echo $? >t.rc.$rc
} & # run the readers in parallel
done
sleep 10
echo result2 start
ls t.rc.* | wc -l
cat t.rc.*
echo result2 end
ps
--
Problem reports: https://cygwin.com/problems.html
FAQ: https://cygwin.com/faq/
Documentation: https://cygwin.com/docs.html
Unsubscribe info: https://cygwin.com/ml/#unsubscribe-simple
