CVS Emacs on Windows XP takes 60 seconds to start

CVS Emacs on Windows XP takes 60 seconds to start

[Francis Litterio]

[-- Attachment #1: Type: text/plain, Size: 962 bytes --]

CVS Emacs built and running on Windows XP seems to perform some network
operations that cause a ~60 second pause after the initial window is
drawn and before the Welcome screen appears.  If I disconnect my network
cable, it starts up quickly (which makes me suspect that it is blocked
on a network access).

I've used SysInternals Process Explorer to get a stack trace of the
thread that seems to be hanging.  It is attached as a PNG image (because
Process Explorer won't let me copy-and-paste from the stack trace
window).  The stack trace shows a call to LsaLookupSids() on the stack,
which might be taking some time since my computer is on a domain.  I've
taken a stack trace at several different times during the hang, and
LsaLookupSids() is always on the stack.

If it copy the install directory to a Windows XP machine that is not on
a domain, Emacs starts without any pause.

Let me know if there's anything additional information I can provide.
--
Fran


[-- Attachment #2: Emacs stack trace --]
[-- Type: image/png, Size: 30797 bytes --]

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Lennart Borgman (gmail)]

Francis Litterio wrote:
> CVS Emacs built and running on Windows XP seems to perform some network
> operations that cause a ~60 second pause after the initial window is
> drawn and before the Welcome screen appears.  If I disconnect my network
> cable, it starts up quickly (which makes me suspect that it is blocked
> on a network access).
> 
> I've used SysInternals Process Explorer to get a stack trace of the
> thread that seems to be hanging.  It is attached as a PNG image (because
> Process Explorer won't let me copy-and-paste from the stack trace
> window).  The stack trace shows a call to LsaLookupSids() on the stack,
> which might be taking some time since my computer is on a domain.  I've
> taken a stack trace at several different times during the hang, and
> LsaLookupSids() is always on the stack.
> 
> If it copy the install directory to a Windows XP machine that is not on
> a domain, Emacs starts without any pause.
> 
> Let me know if there's anything additional information I can provide.


Thanks. Is this when you start with default emacs?

  emacs -Q

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Francis Litterio]

Lennart Borgman (gmail) wrote:

> Francis Litterio wrote:
>> CVS Emacs built and running on Windows XP seems to perform some network
>> operations that cause a ~60 second pause after the initial window is
>> drawn and before the Welcome screen appears.

> Thanks. Is this when you start with default emacs?
>
>   emacs -Q

Sorry for omitting that.  It happens when I run both "emacs -q" and
"emacs -Q".

BUT ... your question has led me to discover an additional strange
symptom: If I wait the ~60 seconds for Emacs to display the Welcome
screen, then terminate Emacs using "C-x C-c", then restart Emacs less
than ~20 seconds after terminating it, it starts without any pause!

It is acting as if the information from the domain controller may be
cached by Windows locally, so that the call to LsaLookupSids() is very
fast when the information is in the cache, but after ~20 seconds, the
domain controller is again contacted over the network.  Just a theory.
--
Fran

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Eli Zaretskii]

> From: Francis Litterio <flitterio@gmail.com>
> Date: Tue, 02 Sep 2008 16:16:55 -0400
> 
> Lennart Borgman (gmail) wrote:
> 
> > Francis Litterio wrote:
> >> CVS Emacs built and running on Windows XP seems to perform some network
> >> operations that cause a ~60 second pause after the initial window is
> >> drawn and before the Welcome screen appears.
> 
> > Thanks. Is this when you start with default emacs?
> >
> >   emacs -Q
> 
> Sorry for omitting that.  It happens when I run both "emacs -q" and
> "emacs -Q".

Is this the first time you built the CVS code?  If not, when was the
last time you built it (and I presume saw no such slowdown)?

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Francis Litterio]

Eli Zaretskii wrote:

>> From: Francis Litterio <flitterio@gmail.com>
>> Date: Tue, 02 Sep 2008 16:16:55 -0400
>> 
>> Lennart Borgman (gmail) wrote:
>> 
>> > Francis Litterio wrote:
>> >> CVS Emacs built and running on Windows XP seems to perform some network
>> >> operations that cause a ~60 second pause after the initial window is
>> >> drawn and before the Welcome screen appears.
>> 
>> > Thanks. Is this when you start with default emacs?
>> >
>> >   emacs -Q
>> 
>> Sorry for omitting that.  It happens when I run both "emacs -q" and
>> "emacs -Q".
>
> Is this the first time you built the CVS code?  If not, when was the
> last time you built it (and I presume saw no such slowdown)?

This has happened with every successful CVS build since my mysterious
build problems disappeared about week ago.  I didn't have time until now
to investigate further.

I have additional information.  My machine has a firewall that blocks
all outbound TCP and UDP traffic _except_ to trusted ports on trusted
hosts (kind of a "whitelist" firewall).  I relaxed my firewall to allow
outbound TCP connections to ports in the range 1025-1035 (the ones most
commonly used by RPC) on any host, and the pause was immediately reduced
to less than 5 seconds (which could be attributed to my domain
controller's slow response time).

As well, after a successful startup in this configuration, the local
cache of information obtained from the domain controller seems to live
for several minutes, because I don't see any RPC traffic to ports
1025-1035 on my domain controller until I start Emacs again after
several minutes.

I think my firewall was causing the ~60 second timeout in RPC calls to
the domain controller.

I would summarize the problem like this: Starting CVS Emacs on a Windows
machine attached to a domain when a firewall prevents RPC communication
with the domain controller, caused a ~60 second pause during startup.

The strange thing is that no other application or Windows functionality
was negatively affected by my firewall rules that blocked outbound TCP
connections to ports in the 1025-1035 range on my domain controllers.
Perhaps Windows uses the SMB ports to communicate with a domain
controller if it can't make an RPC call?
--
Fran

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Francis Litterio]

I wrote:

> The strange thing is that no other application or Windows functionality
> was negatively affected by my firewall rules that blocked outbound TCP
> connections to ports in the 1025-1035 range on my domain controllers.
> Perhaps Windows uses the SMB ports to communicate with a domain
> controller if it can't make an RPC call?

I notice that my firewall rules allow outbound TCP connections to LDAP
servers (port 389) on my network, so that may explain why Windows showed
no functional degradation.
--
Fran

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Lennart Borgman (gmail)]

Francis Litterio wrote:
> Eli Zaretskii wrote:
> 
>>> From: Francis Litterio <flitterio@gmail.com>
>>> Date: Tue, 02 Sep 2008 16:16:55 -0400
>>>
>>> Lennart Borgman (gmail) wrote:
>>>
>>>> Francis Litterio wrote:
>>>>> CVS Emacs built and running on Windows XP seems to perform some network
>>>>> operations that cause a ~60 second pause after the initial window is
>>>>> drawn and before the Welcome screen appears.
>>>> Thanks. Is this when you start with default emacs?
>>>>
>>>>   emacs -Q
>>> Sorry for omitting that.  It happens when I run both "emacs -q" and
>>> "emacs -Q".
..
> The strange thing is that no other application or Windows functionality
> was negatively affected by my firewall rules that blocked outbound TCP
> connections to ports in the 1025-1035 range on my domain controllers.
> Perhaps Windows uses the SMB ports to communicate with a domain
> controller if it can't make an RPC call?


Isn't the most strange thing that it happens for emacs -Q at all?

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Eli Zaretskii]

> Date: Tue, 02 Sep 2008 23:30:49 +0300
> From: Eli Zaretskii <eliz@gnu.org>
> Cc: emacs-devel@gnu.org
> 
> Is this the first time you built the CVS code?  If not, when was the
> last time you built it (and I presume saw no such slowdown)?

Assuming the slowdown started to happen lately, please see if it goes
away if you modify the code of the function `stat' to make this `if'
condition (on w32.c)


  if (!(NILP (Vw32_get_true_file_attributes)
	|| (EQ (Vw32_get_true_file_attributes, Qlocal)
	    && devtype != DRIVE_FIXED && devtype != DRIVE_RAMDISK))
      /* No access rights required to get info.  */
      && (fh = CreateFile (name, 0, 0, NULL, OPEN_EXISTING,
			   FILE_FLAG_BACKUP_SEMANTICS, NULL))
         != INVALID_HANDLE_VALUE)

to always evaluate to zero, thus bypassing the code in the block that
follows the `if' clause and calls get_file_owner_and_group.

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Francis Litterio]

Eli Zaretskii wrote:

>> From: Eli Zaretskii

> Assuming the slowdown started to happen lately, please see if it goes
> away if you modify the code of the function `stat' to make this `if'
> condition (on w32.c)
>
>   if (!(NILP (Vw32_get_true_file_attributes)
> 	|| (EQ (Vw32_get_true_file_attributes, Qlocal)
> 	    && devtype != DRIVE_FIXED && devtype != DRIVE_RAMDISK))
>       /* No access rights required to get info.  */
>       && (fh = CreateFile (name, 0, 0, NULL, OPEN_EXISTING,
> 			   FILE_FLAG_BACKUP_SEMANTICS, NULL))
>          != INVALID_HANDLE_VALUE)
>
> to always evaluate to zero, thus bypassing the code in the block that
> follows the `if' clause and calls get_file_owner_and_group.

Eli,

I changed the above condition to:

   if (0)

and rebuilt.  The resulting emacs.exe starts immediately (both "emacs
-q" and "emacs -Q"), and there are no RPC calls made to any external
host when Emacs is starting.
--
Fran

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Francis Litterio]

I wrote:

> Eli Zaretskii wrote:

>> [...] please see if it goes
>> away if you modify the code of the function `stat' to make this `if'
>> condition (on w32.c)
>>
>>   if (!(NILP (Vw32_get_true_file_attributes)
>> 	|| (EQ (Vw32_get_true_file_attributes, Qlocal)
>> 	    && devtype != DRIVE_FIXED && devtype != DRIVE_RAMDISK))
>>       /* No access rights required to get info.  */
>>       && (fh = CreateFile (name, 0, 0, NULL, OPEN_EXISTING,
>> 			   FILE_FLAG_BACKUP_SEMANTICS, NULL))
>>          != INVALID_HANDLE_VALUE)
>>
>> to always evaluate to zero, thus bypassing the code in the block that
>> follows the `if' clause and calls get_file_owner_and_group.

> I changed the above condition to:
>
>    if (0)
>
> and rebuilt.  The resulting emacs.exe starts immediately (both "emacs
> -q" and "emacs -Q"), and there are no RPC calls made to any external
> host when Emacs is starting.

Eli,

Given that the root cause of this problem is a misconfigured firewall
that prevents the host from making RPC calls to its domain controller(s)
(or LDAP server(s) -- they may be the same on my company's network), I'm
not sure that any change to Emacs is needed.

Is this issue likely to bite other people?  Can we assume that the
Windows host has RPC access to its domain controllers and/or LDAP
servers?
--
Fran

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Jason Rumney]

Francis Litterio wrote:
> Is this issue likely to bite other people?  Can we assume that the
> Windows host has RPC access to its domain controllers and/or LDAP
> servers?
>   

In the case of laptops, you can't assume the domain controller will 
always be there, but perhaps the failure happens more quickly in that 
case (in the firewall case, the system may have enough connectivity to 
the domain controller to not give up so easily).
I haven't noticed such a long delay with my laptop disconnected from the 
company network (though I have noticed delays of around 10 seconds).

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Francis Litterio]

Jason Rumney wrote:

> Francis Litterio wrote:
>> Is this issue likely to bite other people?  Can we assume that the
>> Windows host has RPC access to its domain controllers and/or LDAP
>> servers?

> In the case of laptops, you can't assume the domain controller will always be
> there, but perhaps the failure happens more quickly in that case (in the
> firewall case, the system may have enough connectivity to the domain controller
> to not give up so easily).

I should have added that my firewall silently drops blocked packets,
without sending an ICMP Destination Unreachable or TCP RST to the
source.  I think that's why I had a ~60 second pause with my network
cable plugged in but no pause at all with the cable disconnected.
--
Fran

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Francis Litterio]

Jason Rumney wrote:

> Francis Litterio wrote:
>> Is this issue likely to bite other people?  Can we assume that the
>> Windows host has RPC access to its domain controllers and/or LDAP
>> servers?

> In the case of laptops, you can't assume the domain controller will always be
> there, but perhaps the failure happens more quickly in that case (in the
> firewall case, the system may have enough connectivity to the domain controller
> to not give up so easily).
> I haven't noticed such a long delay with my laptop disconnected from the company
> network (though I have noticed delays of around 10 seconds).

Consider a Windows laptop that is a member of domain and that is plugged
into a LAN that does not contain its domain controllers (e.g., at a LAN
party, a friend's house, a customer site, etc.).  In that case, I
suspect Windows will try to make the RPC calls.  What I'm not sure of is
whether the RPC calls will fail quickly or timeout after ~60 seconds.

I'm not able to test this, because I only have access to one LAN (the
one where my domain controllers exist).
--
Fran

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Eli Zaretskii]

> From: Francis Litterio <flitterio@gmail.com>
> Date: Tue, 02 Sep 2008 20:41:58 -0400
> 
> Is this issue likely to bite other people?  Can we assume that the
> Windows host has RPC access to its domain controllers and/or LDAP
> servers?

Maybe so, but on the other hand, Emacs has no business calling
lookup_account_sid more than once during startup.  See my other
message.

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Eli Zaretskii]

> From: Francis Litterio <flitterio@gmail.com>
> Date: Tue, 02 Sep 2008 17:50:59 -0400
> 
> >   if (!(NILP (Vw32_get_true_file_attributes)
> > 	|| (EQ (Vw32_get_true_file_attributes, Qlocal)
> > 	    && devtype != DRIVE_FIXED && devtype != DRIVE_RAMDISK))
> >       /* No access rights required to get info.  */
> >       && (fh = CreateFile (name, 0, 0, NULL, OPEN_EXISTING,
> > 			   FILE_FLAG_BACKUP_SEMANTICS, NULL))
> >          != INVALID_HANDLE_VALUE)
> >
> > to always evaluate to zero, thus bypassing the code in the block that
> > follows the `if' clause and calls get_file_owner_and_group.
> 
> Eli,
> 
> I changed the above condition to:
> 
>    if (0)
> 
> and rebuilt.  The resulting emacs.exe starts immediately (both "emacs
> -q" and "emacs -Q"), and there are no RPC calls made to any external
> host when Emacs is starting.

Thanks.  I have one more request, assuming you can run Emacs under a
debugger: with the above condition enabled (i.e. revert the code to
what it is in the CVS), can you please verify that lookup_account_sid
is called by `stat' exactly twice during startup: once for the user
who owns the Emacs installation tree (probably you), and one more time
for the primary group of that user.  The rest of files that `stat' is
called for should not cause a call to lookup_account_sid, but instead
should get their user and group name and ID from the cache maintained
by w32_add_to_cache and w32_cached_id.  I'd like to make sure that the
calls to lookup_account_sid are kept to their bare minimum, as
intended, and that there's no bug in the code which handles that part.

Beyond that, I intend to make changes in the code such that the file
security information is requested only when the caller of `stat'
really needs that.  The absolute majority of `stat' calls during
startup come from functions like `file-exists-p' and `load' (via
`openp') that only need to know if the file exists and is a
directory.  I want to modify code so that Emacs doesn't even try to
call lookup_account_sid on behalf of these callers.  This should bring
down the startup time even for situations such as yours, where a
firewall blocks access to LDAP.

Thanks for working on this.

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Stefan Monnier]

> Beyond that, I intend to make changes in the code such that the file
> security information is requested only when the caller of `stat'
> really needs that.  The absolute majority of `stat' calls during
> startup come from functions like `file-exists-p' and `load' (via
> `openp') that only need to know if the file exists and is a
> directory.  I want to modify code so that Emacs doesn't even try to
> call lookup_account_sid on behalf of these callers.  This should bring
> down the startup time even for situations such as yours, where a
> firewall blocks access to LDAP.

Making it lazier is probably a good idea, but if the info will
eventually be needed anyway, maybe we should also eagerly featch this
info (asynchronously).  After all, even a 10s delay is quite noticeable.


        Stefan

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Eli Zaretskii]

> From: Stefan Monnier <monnier@IRO.UMontreal.CA>
> Cc: Francis Litterio <flitterio@gmail.com>, emacs-devel@gnu.org
> Date: Wed, 03 Sep 2008 10:30:24 -0400
> 
> > Beyond that, I intend to make changes in the code such that the file
> > security information is requested only when the caller of `stat'
> > really needs that.  The absolute majority of `stat' calls during
> > startup come from functions like `file-exists-p' and `load' (via
> > `openp') that only need to know if the file exists and is a
> > directory.  I want to modify code so that Emacs doesn't even try to
> > call lookup_account_sid on behalf of these callers.  This should bring
> > down the startup time even for situations such as yours, where a
> > firewall blocks access to LDAP.
> 
> Making it lazier is probably a good idea, but if the info will
> eventually be needed anyway, maybe we should also eagerly featch this
> info (asynchronously).  After all, even a 10s delay is quite noticeable.

The problem is that most callers of `stat' don't need most of the info
in `struct stat'.  This is a system call on Posix platforms, and it is
very fast, so Emacs calls it indiscriminately.  A much better way
would be to abstract several popular uses of `stat' ("does the file
exist?", "is the file executable?", etc.), and then implement that in
the most efficient way on every supported platform.  But I guess such
refactoring will have to wait for some rainy day.

The only Emacs primitives that _really_ need all of the info in
`struct stat' are `file-attributes' and `directory-files-and-attributes'.

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Stefan Monnier]

> The only Emacs primitives that _really_ need all of the info in
> `struct stat' are `file-attributes' and `directory-files-and-attributes'.

Then again, most callers of file-attributes similarly only use some
subset of the info. :-(


        Stefan

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Eli Zaretskii]

> From: Stefan Monnier <monnier@IRO.UMontreal.CA>
> Cc: flitterio@gmail.com, emacs-devel@gnu.org
> Date: Wed, 03 Sep 2008 14:40:19 -0400
> 
> > The only Emacs primitives that _really_ need all of the info in
> > `struct stat' are `file-attributes' and `directory-files-and-attributes'.
> 
> Then again, most callers of file-attributes similarly only use some
> subset of the info. :-(

But normally they do need attributes getting which is worth the
trouble.  Barring those cases where file-attributes is used where
file-exists-p or some such would suffice, of course; but those are
bugs.

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Francis Litterio]

Eli Zaretskii wrote:

> I have one more request, assuming you can run Emacs under a
> debugger: with the above condition enabled (i.e. revert the code to
> what it is in the CVS), can you please verify that lookup_account_sid
> is called by `stat' exactly twice during startup: once for the user
> who owns the Emacs installation tree (probably you), and one more time
> for the primary group of that user.

I did that, though I took a more crude approach than using a debugger: I
added an fprintf() call to the end of lookup_account_sid() to display
the "Name" and "DomainName" being returned.

When I run "emacs -q" or "emacs -Q", lookup_account_sid() is called
twice.  The first call returns my user ID and domain name.  The second
call returns the Name "Administrators" and DomainName is NULL (I assume
this references the Local Administrators group).  However, that is _not_
my primary group.

When I exit Emacs, there is a third call to lookup_account_sid().  It
returns the Name "Domain Users" and the DomainName "CORP", which _is_ my
primary group.

> Thanks for working on this.

No problem.
--
Fran

Re: CVS Emacs on Windows XP takes 60 seconds to start

[Eli Zaretskii]

> From: Francis Litterio <flitterio@gmail.com>
> Date: Wed, 03 Sep 2008 11:14:47 -0400
> 
> When I run "emacs -q" or "emacs -Q", lookup_account_sid() is called
> twice.  The first call returns my user ID and domain name.  The second
> call returns the Name "Administrators" and DomainName is NULL (I assume
> this references the Local Administrators group).  However, that is _not_
> my primary group.
> 
> When I exit Emacs, there is a third call to lookup_account_sid().  It
> returns the Name "Domain Users" and the DomainName "CORP", which _is_ my
> primary group.

Thanks.