Bash / cygwin process spawning (?) performance very slow

[l***@null.net]

Hi all,

I noticed that doing simple loops in Bash takes unexpectedly long under Cygwin on a Windows XP 32 bit machine
(CYGWIN_NT-5.1 <machine> 2.2.1(0.289/5/3) 2015-08-20 11:40 i686 Cygwin)

I already followed the FAQ advice in trying to determine general causes, and made a 'shadow' copy of /etc/passwd as described.
My PATH does not contain references to network shares.

Still quite normal commands take a long time e.g.
time cat some-file | while read i;do echo $i;/bin/true;done

real 1m44.953s
user 0m9.599s
sys 1m36.865s

for a file of 167 lines. Process Explorer showed a CPU load of 20% on bash.exe, which was almost completely Kernel time.
Is such high Kernel load normal?

I know it's a bit like comparing apples to oranges, but I run the SAME command from the same disk, from within a Debian 7 486 Linux on VirtualBox (!) on the same machine, it gave
real 0m3.871s
user 0m0.160s
sys 0m3.292s

So even running in emulator, real/user/sys time are about 30/60/30 times faster. That's quite shocking.
Is this performance to be expected? That would make it an obvious choice to switch to VirtualBox on this machine.

Thanks,
Paul

--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[Helmut Karlowski]

***@null.net:
Wed, 23 Sep 2015 10:52:26 +0200
---------------------------------------------------

Post by l***@null.net
Hi all,
I noticed that doing simple loops in Bash takes unexpectedly long under Cygwin on a Windows XP 32 bit machine
(CYGWIN_NT-5.1 <machine> 2.2.1(0.289/5/3) 2015-08-20 11:40 i686 Cygwin)
I already followed the FAQ advice in trying to determine general causes, and made a 'shadow' copy of /etc/passwd as described.
My PATH does not contain references to network shares.
Still quite normal commands take a long time e.g.
time cat some-file | while read i;do echo $i;/bin/true;done
real 1m44.953s
user 0m9.599s
sys 1m36.865s

#wc t; time cat t | while read i;do echo $i;/bin/true;done >/dev/null
172 172 3448 t
3.73s real 0.04s user 0.43s system

On cygwin 1.7.35 and XP32. Not THAT fast but similar to your
linux-result. I guess your antivirus is interfering. I've configured
my avast to not deep-scan anything in C:\cygwin\bin, maybe that helps.

-Helmut


--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[Marco Atzeri]

Post by l***@null.net
Hi all,
I noticed that doing simple loops in Bash takes unexpectedly long under Cygwin on a Windows XP 32 bit machine
(CYGWIN_NT-5.1 <machine> 2.2.1(0.289/5/3) 2015-08-20 11:40 i686 Cygwin)
I already followed the FAQ advice in trying to determine general causes, and made a 'shadow' copy of /etc/passwd as described.
My PATH does not contain references to network shares.
Still quite normal commands take a long time e.g.
time cat some-file | while read i;do echo $i;/bin/true;done
real 1m44.953s
user 0m9.599s
sys 1m36.865s
for a file of 167 lines. Process Explorer showed a CPU load of 20% on bash.exe, which was almost completely Kernel time.
Is such high Kernel load normal?

may be. forks are time consuming and your command is spending all the
time in fork

In addition, I suspect your Antivirus is further slowing down the things.

Post by l***@null.net
I know it's a bit like comparing apples to oranges, but I run the SAME command from the same disk, from within a Debian 7 486 Linux on VirtualBox (!) on the same machine, it gave
real 0m3.871s
user 0m0.160s
sys 0m3.292s
So even running in emulator, real/user/sys time are about 30/60/30 times faster. That's quite shocking.
Is this performance to be expected? That would make it an obvious choice to switch to VirtualBox on this machine.

I have much better results with my cygwin
also with a much longer file

$ wc -l cygcheck.out
5220 cygcheck.out

$ time cat cygcheck.out | while read i;do grep text $i;done
..
real 0m0.288s
user 0m0.015s
sys 0m0.262s

$ time awk '{if ($1 ~ /text/) print $1}' cygcheck.out
...
real 0m0.076s
user 0m0.015s
sys 0m0.046s

Post by l***@null.net
Thanks,
Paul

for every job there is the right tool
:-0

Regards
Marco





--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[l***@null.net]

Post by Marco Atzeri

Post by l***@null.net
for a file of 167 lines. Process Explorer showed a CPU load of 20% on bash.exe, which was almost completely Kernel time.
Is such high Kernel load normal?

may be. forks are time consuming and your command is spending all the
time in fork

So why is it spending all its time in fork? That is the question.

Post by Marco Atzeri
In addition, I suspect your Antivirus is further slowing down the things.

I don't run an Antivirus program

Post by Marco Atzeri
I have much better results with my cygwin
also with a much longer file
$ wc -l cygcheck.out
5220 cygcheck.out
$ time cat cygcheck.out | while read i;do grep text $i;done
..
real 0m0.288s
user 0m0.015s
sys 0m0.262s

Thanks for your measurement, it confirms the issue is with my installation.
Still the question remains, why is it so slow, spending all its time in kernel mode?

Paul


--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[Marco Atzeri]

Post by l***@null.net

Post by Marco Atzeri

Post by l***@null.net
for a file of 167 lines. Process Explorer showed a CPU load of 20% on bash.exe, which was almost completely Kernel time.
Is such high Kernel load normal?

may be. forks are time consuming and your command is spending all the
time in fork

So why is it spending all its time in fork? That is the question.

https://cygwin.com/faq.html#faq.api.fork

Post by l***@null.net

Post by Marco Atzeri
In addition, I suspect your Antivirus is further slowing down the things.

I don't run an Antivirus program

than some thing else is crashing your performance
https://cygwin.com/faq/faq.html#faq.using.bloda


--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[l***@null.net]

Post by Helmut Karlowski
Wed, 23 Sep 2015 10:52:26 +0200
---------------------------------------------------

Post by l***@null.net
Hi all,
I noticed that doing simple loops in Bash takes unexpectedly long under Cygwin on a Windows XP 32 bit machine
(CYGWIN_NT-5.1 <machine> 2.2.1(0.289/5/3) 2015-08-20 11:40 i686 Cygwin)
I already followed the FAQ advice in trying to determine general causes, and made a 'shadow' copy of /etc/passwd as described.
My PATH does not contain references to network shares.
Still quite normal commands take a long time e.g.
time cat some-file | while read i;do echo $i;/bin/true;done
real 1m44.953s
user 0m9.599s
sys 1m36.865s

#wc t; time cat t | while read i;do echo $i;/bin/true;done >/dev/null
172 172 3448 t
3.73s real 0.04s user 0.43s system
On cygwin 1.7.35 and XP32. Not THAT fast but similar to your
linux-result. I guess your antivirus is interfering. I've configured
my avast to not deep-scan anything in C:\cygwin\bin, maybe that helps.
-Helmut

Thanks for the reply Helmut,

Although the /dev/null probably contributes a bit to the timing
it's clear not all 32 bit XP systems suffer from this, thanks for that!

I'm not running any antivirus as far as I'm aware of (I do run a Comodo firewall with all "virus" scanning disabled).
I checked again, and it really is the Bash.exe which is consuming a lot of Kernel time. I didn't spot another process kicking in and consuming cycles.

Any idea how to diagnose the cause of this? Is there any Cygwin specific logging/tracing to see where it is happening?

Thanks,
Paul


--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[Helmut Karlowski]

---------------------------------------------------

Post by l***@null.net
I'm not running any antivirus as far as I'm aware of (I do run a Comodo firewall with all "virus" scanning disabled).
I checked again, and it really is the Bash.exe which is consuming a lot of Kernel time. I didn't spot another process kicking in and consuming cycles.

You can do the same in dash (sans time) for example to rule out bash.

Post by l***@null.net
Any idea how to diagnose the cause of this? Is there any Cygwin specific logging/tracing to see where it is happening?

Maybe:

strace bash -c 'time cat some-file | while read i;do echo
$i;/bin/true;done'

Haven't tested it.

Simplify the command:

for((i=0;i<150;i++));do /bin/true;done

to rule out a pipe-problem.

-Helmut


--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[l***@null.net]

Post by Marco Atzeri

Post by l***@null.net

Post by Marco Atzeri

Post by l***@null.net
for a file of 167 lines. Process Explorer showed a CPU load of 20% on bash.exe, which was almost completely Kernel time.
Is such high Kernel load normal?

may be. forks are time consuming and your command is spending all the
time in fork

So why is it spending all its time in fork? That is the question.

https://cygwin.com/faq.html#faq.api.fork

That doesn't answer my question on Kernel load. Why is it fast on your machine, and slow on mine?
How can I find the culprit?

Post by Marco Atzeri

Post by l***@null.net

Post by Marco Atzeri
In addition, I suspect your Antivirus is further slowing down the things.

I don't run an Antivirus program

than some thing else is crashing your performance
https://cygwin.com/faq/faq.html#faq.using.bloda

Obviously something is. The FAQ entry does not mention performance, but real failures.
How to further diagnose this?

Best regards,
Paul

--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[Marco Atzeri]

Post by l***@null.net
Obviously something is. The FAQ entry does not mention performance, but real failures.
How to further diagnose this?

together with the cygcheck output that I already mentioned
I suggest

1) to look on

/proc/self/maps or /proc/<PID>/maps

to looks for strange DLL loaded

2) try to use strace.
However usually strace impact the timing and the problem can never arise.

Post by l***@null.net
Best regards,
Paul

--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[l***@null.net]

Post by l***@null.net
Obviously something is. The FAQ entry does not mention performance, but real failures.
How to further diagnose this?

I took the plunge and spent almost a full day trying to find the cause.

1. Booting into Safe Mode gave a huge performance boost
2. By eliminating all services and programs in Normal Mode, one-by-one, I found the offender:

turns out that Comodo Firewall (Free version) loads a DLL in each process that is the cause of the delay.
Although I only use the Firewall, and do not use any "AntiVirus" features, still it causes delay during startup of a process.

However, after disabling it -- which did speed up process spawning in Bash -- I encountered the other problem I already had much more often.
For now I consider the issue of slow spawning to be solved
(although it would have been nice if there was an easier way to diagnose it, maybe with tracing?)

Regards,
Paul

--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[Cliff Hones]

Post by l***@null.net

Post by l***@null.net
Obviously something is. The FAQ entry does not mention performance, but real failures.
How to further diagnose this?

I took the plunge and spent almost a full day trying to find the cause.
1. Booting into Safe Mode gave a huge performance boost
turns out that Comodo Firewall (Free version) loads a DLL in each process that is the cause of the delay.
Although I only use the Firewall, and do not use any "AntiVirus" features, still it causes delay during startup of a process.
However, after disabling it -- which did speed up process spawning in Bash -- I encountered the other problem I already had much more often.
For now I consider the issue of slow spawning to be solved
(although it would have been nice if there was an easier way to diagnose it, maybe with tracing?)

Comodo firewall pro is listed in https://cygwin.com/faq/faq.html#faq.using.bloda.
Looks as if the free version should be listed too.


--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[Lee]

Post by l***@null.net

Post by l***@null.net
Obviously something is. The FAQ entry does not mention performance, but real failures.
How to further diagnose this?

I took the plunge and spent almost a full day trying to find the cause.

... snip ...

Post by l***@null.net
turns out that Comodo Firewall (Free version) loads a DLL in each process
that is the cause of the delay.

... snip ...

Post by l***@null.net
(although it would have been nice if there was an easier way to diagnose it,
maybe with tracing?)

If you use http://www.dependencywalker.com/ on bash.exe with view/full
paths enabled, does the Comodo Firewall dll stand out or is it just
another .dll loaded from windows\system32?

Regards,
Lee

--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[Marco Atzeri]

Post by Lee

Post by l***@null.net

Post by l***@null.net
Obviously something is. The FAQ entry does not mention performance, but
real failures.
How to further diagnose this?

I took the plunge and spent almost a full day trying to find the cause.

... snip ...

Post by l***@null.net
turns out that Comodo Firewall (Free version) loads a DLL in each process
that is the cause of the delay.

... snip ...

Post by l***@null.net
(although it would have been nice if there was an easier way to diagnose it,
maybe with tracing?)

Tracing may report it as at process load is reporting
the loaded dll's

--- Process 7380 loaded C:\Windows\System32\ntdll.dll at 0000000077360000
--- Process 7380 loaded C:\Windows\System32\kernel32.dll at 0000000077240000
--- Process 7380 loaded C:\Windows\System32\KernelBase.dll at
000007FEFDB20000
--- Process 7380 loaded C:\Windows\System32\sysfer.dll at 0000000074B40000
--- Process 7380 loaded E:\cygwin64\bin\cygwin1.dll at 0000000180040000
--- Process 7380 loaded E:\cygwin64\bin\cygiconv-2.dll at 00000003C2700000
--- Process 7380 loaded E:\cygwin64\bin\cygintl-8.dll at 00000003BEC90000
--- Process 7380 loaded E:\cygwin64\bin\cygncursesw-10.dll at
00000003BD880000
--- Process 7380 loaded E:\cygwin64\bin\cygreadline7.dll at 00000003B5FD0000
--- Process 7380 loaded C:\Windows\System32\user32.dll at 0000000076C60000
--- Process 7380 loaded C:\Windows\System32\gdi32.dll at 000007FEFEBE0000
--- Process 7380 loaded C:\Windows\System32\lpk.dll at 000007FEFF3C0000
--- Process 7380 loaded C:\Windows\System32\usp10.dll at 000007FEFF500000
--- Process 7380 loaded C:\Windows\System32\msvcrt.dll at 000007FEFF5D0000

Post by Lee
If you use http://www.dependencywalker.com/ on bash.exe with view/full
paths enabled, does the Comodo Firewall dll stand out or is it just
another .dll loaded from windows\system32?

unlikely to appear as it is not a dependency but an injected dll

Post by Lee
Regards,
Lee

--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[l***@null.net]

Post by Helmut Karlowski
strace bash -c 'time cat some-file | while read i;do echo
$i;/bin/true;done'
Haven't tested it.
for((i=0;i<150;i++));do /bin/true;done
to rule out a pipe-problem.

Thanks for the tips! Used a variant on the for loop to simplify the problem.

Regards,
Paul

--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[l***@null.net]

Post by Lee
If you use http://www.dependencywalker.com/ on bash.exe with view/full
paths enabled, does the Comodo Firewall dll stand out or is it just
another .dll loaded from windows\system32?
Regards,
Lee

I use Process Explorer to view in-process .dlls:

C:\WINDOWS\system32\guard32.dll

Regards,
Paul

--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple

[l***@null.net]

Post by l***@null.net
turns out that Comodo Firewall (Free version) loads a DLL in each process that is the cause of the delay.
Although I only use the Firewall, and do not use any "AntiVirus" features, still it causes delay during startup of a process.
However, after disabling it -- which did speed up process spawning in Bash -- I encountered the other problem I already had much more often.
For now I consider the issue of slow spawning to be solved
(although it would have been nice if there was an easier way to diagnose it, maybe with tracing?)

After some more experimenting, and reading on Comodo issues in combination with Chrome, I found the following solution:
Add the cygwin installation folder to Comodo's 'Detect Shellcode Injections Exclusions' setting. This will lead to an immediate drop
in 'spawn' times to more acceptable levels. Somehow 'Detect Shellcode Injections' is active, even when HIPS is disabled.

Paul


--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple