possible cygwin bug: delays when using pipes
Eugene Rosenzweig
eugenius259@iprimus.com.au
Wed Jan 15 15:59:00 GMT 2003
Seemingly, whenever I use a pipe in bash the cygwin freezes for a long time.
For example:
'echo a | cat' takes about 10 seconds to execute, 'bash -l -i' takes about a
minute.
I am not sure when the problem appeared. Might have been last cygwin dll
release but I am not sure. First time I noticed was running 'bash -l -i'. I
changed the cygwin.bat recently so for a while I thought it was my meddling
but as far as I can see that is not the case. Right now the cygwin is quite
unusable since any non-trivial command line takes a long time to execute.
My startup script:
@echo off
set HOME=D:\DEV\CYGWIN\home\eugene
set TERM=ansi
rem D:
rem chdir \dev\cygwin\bin
IF NOT "x%1" == "x" ( cd %1 ) ELSE ( cd %HOME% )
d:\dev\cygwin\bin\bash --login -i
Here are the results for
strace -f -m thread bash -i -l
of which I can not make out much at all apart from the fact that certain
combination of calls (read_pipe followed WFMO message) takes 10 seconds each
:
8461 8461 [main] bash 3692 cygthread::cygthread: name sig, id 0xF20
54541 63002 [main] bash 3692 cygthread::cygthread: name proc, id 0xF54
17409 80411 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0x9B0
9713344 9793755 [main] bash 3692 cygthread::detach: WFMO returns 0, id 0x0
1395 9795150 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
9982585 19777735 [main] bash 3692 cygthread::detach: WFMO returns 1, id
0xD04
10042750 29820485 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
9958336 39778821 [main] bash 3692 cygthread::detach: WFMO returns 1, id
0xD04
212 39779033 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
5883 39784916 [main] bash 3692 cygthread::detach: WFMO returns 1, id 0xD04
39658 39824574 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
10007110 49831684 [main] bash 3692 cygthread::detach: WFMO returns 1, id
0xD04
2207 49833891 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
5329 49839220 [main] bash 3692 cygthread::detach: WFMO returns 0, id 0xD04
8461 8461 [main] bash 3692 cygthread::cygthread: name sig, id 0xF20
54541 63002 [main] bash 3692 cygthread::cygthread: name proc, id 0xF54
17409 80411 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0x9B0
9713344 9793755 [main] bash 3692 cygthread::detach: WFMO returns 0, id 0x0
1395 9795150 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
9982585 19777735 [main] bash 3692 cygthread::detach: WFMO returns 1, id
0xD04
10042750 29820485 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
9958336 39778821 [main] bash 3692 cygthread::detach: WFMO returns 1, id
0xD04
212 39779033 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
5883 39784916 [main] bash 3692 cygthread::detach: WFMO returns 1, id 0xD04
39658 39824574 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
10007110 49831684 [main] bash 3692 cygthread::detach: WFMO returns 1, id
0xD04
2207 49833891 [main] bash 3692 cygthread::cygthread: name read_pipe, id
0xD04
5329 49839220 [main] bash 3692 cygthread::detach: WFMO returns 0, id 0xD04
Also, when finally in bash, results of 'echo a | strace -f -m syscall,thread
cat'
where the delay is in read_pipe then WMFO pair:
6287 6287 [main] cat 2432 normalize_posix_path: src /etc/passwd
745 7032 [main] cat 2432 symlink_info::check: not a symlink
94 7126 [main] cat 2432 symlink_info::check: 0 = symlink.check
(D:\dev\cygwin\etc\passwd, 0x22F7C8) (0xA)
522 7648 [main] cat 2432 normalize_posix_path: src /etc/group
415 8063 [main] cat 2432 symlink_info::check: not a symlink
78 8141 [main] cat 2432 symlink_info::check: 0 = symlink.check
(D:\dev\cygwin\etc\group, 0x22F7A8) (0xA)
407 8548 [main] cat 2432 _cygwin_istext_for_stdio:
_cygwin_istext_for_stdio (0)
57 8605 [main] cat 2432 _cygwin_istext_for_stdio: _cifs: fd not open
34 8639 [main] cat 2432 _cygwin_istext_for_stdio:
_cygwin_istext_for_stdio (1)
33 8672 [main] cat 2432 _cygwin_istext_for_stdio: _cifs: fd not open
32 8704 [main] cat 2432 _cygwin_istext_for_stdio:
_cygwin_istext_for_stdio (2)
31 8735 [main] cat 2432 _cygwin_istext_for_stdio: _cifs: fd not open
407 9142 [main] cat 2432 cygthread::cygthread: name sig, id 0xD4C
704 9846 [main] cat 2432 normalize_posix_path: src /dev/piper
264 10110 [main] cat 2432 fhandler_base::set_flags: filemode set to
binary
3083 13193 [main] cat 2432 normalize_posix_path: src
/home/eugene/strace.txt
481 13674 [main] cat 2432 symlink_info::check: not a symlink
98 13772 [main] cat 2432 symlink_info::check: 0 = symlink.check
(D:\dev\cygwin\home\eugene\strace.txt, 0x22F488) (0xA)
191 13963 [main] cat 2432 fhandler_base::set_flags: filemode set to
binary
177 14140 [main] cat 2432 normalize_posix_path: src /dev/conout
305 14445 [main] cat 2432 tty_min::set_ctty: attached tty1073741824 sid
2432, pid 2432, tty->pgid 0, tty->sid 2432
2873 17318 [main] cat 2432 fhandler_base::set_flags: filemode set to
binary
443 17761 [main] cat 2432 fhandler_console::output_tcsetattr: 0 =
tcsetattr (,A020018) (ENABLE FLAGS 3) (lflag 107 oflag 9)
322 18083 [main] cat 2432 normalize_posix_path: src
D:\dev\cygwin\home\eugene\strace.txt
520 18603 [main] cat 2432 symlink_info::check: not a symlink
91 18694 [main] cat 2432 symlink_info::check: 0 = symlink.check
(D:\dev\cygwin\home\eugene\strace.txt, 0x22F578) (0xA)
180 18874 [main] cat 2432 fhandler_disk_file::fstat_helper: 0 = fstat (,
0x22FD98) st_atime=3E2409D0 st_size=2238, st_mode=0x81A4, st_ino=-136640046,
sizeof=88
46 18920 [main] cat 2432 fstat64: 0 = fstat (1, 0x22FD98)
48 18968 [main] cat 2432 isatty: 0 = isatty (1)
50 19018 [main] cat 2432 isatty: 0 = isatty (1)
89 19107 [main] cat 2432 fhandler_base::set_flags: filemode set to
binary
33 19140 [main] cat 2432 _cygwin_istext_for_stdio:
_cygwin_istext_for_stdio (1)
35 19175 [main] cat 2432 _cygwin_istext_for_stdio: _cifs: get_*_binary
41 19216 [main] cat 2432 setmode_helper: setmode: file was raw now raw
35 19251 [main] cat 2432 setmode: setmode (1</home/eugene/strace.txt>,
0x10000) returns binary
38 19289 [main] cat 2432 isatty: 0 = isatty (0)
34 19323 [main] cat 2432 isatty: 0 = isatty (0)
85 19408 [main] cat 2432 fhandler_base::set_flags: filemode set to
binary
33 19441 [main] cat 2432 _cygwin_istext_for_stdio:
_cygwin_istext_for_stdio (0)
33 19474 [main] cat 2432 _cygwin_istext_for_stdio: _cifs: fd not disk
file
34 19508 [main] cat 2432 setmode_helper: setmode: file was raw now raw
34 19542 [main] cat 2432 setmode: setmode (0</dev/piper>, 0x10000)
returns binary
39 19581 [main] cat 2432 normalize_posix_path: src \dev\piper
195 19776 [main] cat 2432 cwdstuff::get: (D:\dev\cygwin\home\eugene) =
cwdstuff::get (0x22F288, 260, 0, 0), errno 0
789 20565 [main] cat 2432 geterrno_from_win_error: windows error 2 ==
errno 2
248 20813 [main] cat 2432 geterrno_from_win_error: windows error 2 ==
errno 2
43 20856 [main] cat 2432 symlink_info::check: 0 = symlink.check
(d:\dev\piper, 0x22F578) (0x22)
222 21078 [main] cat 2432 symlink_info::check: not a symlink
49 21127 [main] cat 2432 symlink_info::check: 0 = symlink.check
(d:\dev, 0x22F578) (0x22)
148 21275 [main] cat 2432 fstat64: 0 = fstat (0, 0x22FD98)
101 21376 [main] cat 2432 readv: readv (0, 0x22FD88, 1) blocking,
sigcatchers 0
258 21634 [main] cat 2432 cygthread::cygthread: name read_pipe, id 0xA78
10639163 10660797 [main] cat 2432 cygthread::detach: WFSO returns 0, id
0xA78
247 10661044 [main] cat 2432 readv: 2 = readv (0, 0x22FD88, 1), errno 0
a
185 10661229 [main] cat 2432 readv: readv (0, 0x22FD88, 1) blocking,
sigcatchers 0
44 10661273 [main] cat 2432 cygthread::cygthread: name read_pipe, id
0xA78
118 10661391 [main] cat 2432 cygthread::detach: WFSO returns 0, id 0xA78
83 10661474 [main] cat 2432 readv: 0 = readv (0, 0x22FD88, 1), errno 0
86 10661560 [main] cat 2432 close: close (0)
36 10661596 [main] cat 2432 fhandler_base::close: closing '/dev/piper'
handle 0x8C
50 10661646 [main] cat 2432 close: 0 = close (0)
60 10661706 [main] cat 2432 do_exit: do_exit (0)
46 10661752 [main] cat 2432 void: 0x0 = signal (20, 0x1)
37 10661789 [main] cat 2432 void: 0x0 = signal (1, 0x1)
35 10661824 [main] cat 2432 void: 0x0 = signal (2, 0x1)
34 10661858 [main] cat 2432 void: 0x0 = signal (3, 0x1)
35 10661893 [main] cat 2432 fhandler_base::close: closing
'/home/eugene/strace.txt' handle 0x700
271 10662164 [main] cat 2432 __to_clock_t: dwHighDateTime 0, dwLowDateTime
312500
42 10662206 [main] cat 2432 __to_clock_t: total 00000000 0000001F
38 10662244 [main] cat 2432 __to_clock_t: dwHighDateTime 0, dwLowDateTime
312500
36 10662280 [main] cat 2432 __to_clock_t: total 00000000 0000001F
I have attached the cygsheck -s -v -r output.
I hope someone can shed some light on my situation.
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: cygcheck-s-v-r.txt
URL: <http://cygwin.com/pipermail/cygwin/attachments/20030115/21a230c6/attachment.txt>
-------------- next part --------------
--
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple
Bug reporting: http://cygwin.com/bugs.html
Documentation: http://cygwin.com/docs.html
FAQ: http://cygwin.com/faq/
More information about the Cygwin
mailing list