Bash / cygwin process spawning (?) performance very slow

Bash / cygwin process spawning (?) performance very slow

[litter]

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

Re: Bash / cygwin process spawning (?) performance very slow

[Helmut Karlowski]

litter@null.net:
Wed, 23 Sep 2015 10:52:26 +0200
---------------------------------------------------
> 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

Re: Bash / cygwin process spawning (?) performance very slow

[Marco Atzeri]

On 23/09/2015 10:52, litter@null.net wrote:
> 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.

> 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


> 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

Re: Bash / cygwin process spawning (?) performance very slow

[litter]

>> 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.
 
> In addition, I suspect your Antivirus is further slowing down the things.

I don't run an Antivirus program
 
> 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

Re: Bash / cygwin process spawning (?) performance very slow

[Marco Atzeri]

On 23/09/2015 17:17, litter@null.net wrote:
>>> 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

>
>> 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

Re: Bash / cygwin process spawning (?) performance very slow

[litter]

> On 23/09/2015 17:17, litter@null.net wrote:
>>>> 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?
 
>>
>>> 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

Re: Bash / cygwin process spawning (?) performance very slow

[Marco Atzeri]

On 24/09/2015 11:57, litter@null.net wrote:
> 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.

>
> 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

Re: Bash / cygwin process spawning (?) performance very slow

[litter]

> On 24/09/2015 11:57, litter@null.net wrote:
>> 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

Re: Bash / cygwin process spawning (?) performance very slow

[Cliff Hones]

On 24/09/2015 18:24, litter@null.net wrote:
>> On 24/09/2015 11:57, litter@null.net wrote:
>>> 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?)

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

Re: Bash / cygwin process spawning (?) performance very slow

[Lee]

On 9/24/15, litter wrote:
>> On 24/09/2015 11:57, litter wrote:
>>> 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 ...
> turns out that Comodo Firewall (Free version) loads a DLL in each process
> that is the cause of the delay.
    ... snip ...
> (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

Re: Bash / cygwin process spawning (?) performance very slow

[Marco Atzeri]

On 24/09/2015 19:46, Lee wrote:
> On 9/24/15, litter wrote:
>>> On 24/09/2015 11:57, litter wrote:
>>>> 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 ...
>> turns out that Comodo Firewall (Free version) loads a DLL in each process
>> that is the cause of the delay.
>      ... snip ...
>> (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


> 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

>
> 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

Re: Bash / cygwin process spawning (?) performance very slow

[litter]

> 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

Solved Re: Bash / cygwin process spawning (?) performance very slow

[litter]

> 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

Re: Bash / cygwin process spawning (?) performance very slow

[litter]

> litter@null.net:
> Wed, 23 Sep 2015 10:52:26 +0200
> ---------------------------------------------------
>> 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

Re: Bash / cygwin process spawning (?) performance very slow

[Helmut Karlowski]

---------------------------------------------------
> 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.

> 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

Re: Bash / cygwin process spawning (?) performance very slow

[litter]

> 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.

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