zsh hangs loading init files

zsh hangs loading init files

[Greg Klanderman]

Hi all,

I'm in the process of transitioning my work computer from debian 5.0
(lenny) to an Ubuntu variant that Google uses (Goobuntu) and having
trouble with newer versions of zsh.  While loading my init files, zsh
hangs several times for 10-30 sec.  This is not happening on 4.3.10
which came with the Goobuntu distribution, or a 4.3.10 which I built
from source, but is occurring with 4.3.15 and a cvs checkout in
between 4.3.11 and 4.3.12 which I built.  I do not see the problem on
my old debian box.

By putting in some print statements, the first hang seems to occur
at a command substitution

| case "$(uname -s)" in
|   ...

the last bit of strace up to the hang is:

rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [CHLD], [CHLD], 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [CHLD], [CHLD], 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [CHLD], [CHLD], 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [CHLD], [CHLD], 8) = 0
rt_sigaction(SIGINT, {0x476250, [], SA_RESTORER|SA_INTERRUPT, 0x7f883f6c1af0}, NULL, 8) = 0
rt_sigaction(SIGINT, {0x476250, [], SA_RESTORER|SA_INTERRUPT, 0x7f883f6c1af0}, NULL, 8) = 0
rt_sigaction(SIGINT, {0x476250, [], SA_RESTORER|SA_INTERRUPT, 0x7f883f6c1af0}, NULL, 8) = 0
rt_sigaction(SIGINT, {0x476250, [], SA_RESTORER|SA_INTERRUPT, 0x7f883f6c1af0}, NULL, 8) = 0
rt_sigaction(SIGINT, {0x476250, [], SA_RESTORER|SA_INTERRUPT, 0x7f883f6c1af0}, NULL, 8) = 0
rt_sigaction(SIGINT, {0x476250, [], SA_RESTORER|SA_INTERRUPT, 0x7f883f6c1af0}, NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
pipe([3, 4])                            = 0
fcntl(3, F_DUPFD, 10)                   = 13
close(3)                                = 0
fcntl(4, F_DUPFD, 10)                   = 14
close(4)                                = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f88402d89d0) = 26368
close(14)                               = 0
fcntl(13, F_GETFL)                      = 0 (flags O_RDONLY)
fstat(13, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f88402de000
lseek(13, 0, SEEK_CUR)                  = -1 ESPIPE (Illegal seek)
read(13, ######## hangs here for 10-30 sec then continues

I suppose at this point I will binary search for the commit that broke
things and go from there, but wanted to put this out in case anyone
has any ideas what it might be.

thanks,
Greg

Re: zsh hangs loading init files

[Dan Nelson]

In the last episode (Jan 05), Greg Klanderman said:
> 
> Hi all,
> 
> I'm in the process of transitioning my work computer from debian 5.0
> (lenny) to an Ubuntu variant that Google uses (Goobuntu) and having
> trouble with newer versions of zsh.  While loading my init files, zsh
> hangs several times for 10-30 sec.  This is not happening on 4.3.10
> which came with the Goobuntu distribution, or a 4.3.10 which I built
> from source, but is occurring with 4.3.15 and a cvs checkout in
> between 4.3.11 and 4.3.12 which I built.  I do not see the problem on
> my old debian box.
> 
> By putting in some print statements, the first hang seems to occur
> at a command substitution
> 
> | case "$(uname -s)" in
> |   ...
> 
> the last bit of strace up to the hang is:
> 
> pipe([3, 4])                            = 0
> fcntl(3, F_DUPFD, 10)                   = 13
> close(3)                                = 0
> fcntl(4, F_DUPFD, 10)                   = 14
> close(4)                                = 0
> rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
> clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f88402d89d0) = 26368
> close(14)                               = 0
> fcntl(13, F_GETFL)                      = 0 (flags O_RDONLY)
> fstat(13, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f88402de000
> lseek(13, 0, SEEK_CUR)                  = -1 ESPIPE (Illegal seek)
> read(13, ######## hangs here for 10-30 sec then continues

zsh isn't hanging; it's just waiting for the output of its forked child
process (uname).  Try adding "-f" to your strace commandline, to follow
child processes.
 
-- 
	Dan Nelson
	dnelson@allantgroup.com

Re: zsh hangs loading init files

[Greg Klanderman]

yes, thanks.

looks like maybe HASH_DIRS logic was changed and is now stat()ing
every potential executable it finds, whereas it used to only
getdents() on all the dirs in your path.

still haven't found the changeset.

greg


>>>>> On January 5, 2012 Dan Nelson <dnelson@allantgroup.com> wrote:

> In the last episode (Jan 05), Greg Klanderman said:
>> 
>> Hi all,
>> 
>> I'm in the process of transitioning my work computer from debian 5.0
>> (lenny) to an Ubuntu variant that Google uses (Goobuntu) and having
>> trouble with newer versions of zsh.  While loading my init files, zsh
>> hangs several times for 10-30 sec.  This is not happening on 4.3.10
>> which came with the Goobuntu distribution, or a 4.3.10 which I built
>> from source, but is occurring with 4.3.15 and a cvs checkout in
>> between 4.3.11 and 4.3.12 which I built.  I do not see the problem on
>> my old debian box.
>> 
>> By putting in some print statements, the first hang seems to occur
>> at a command substitution
>> 
>> | case "$(uname -s)" in
>> |   ...
>> 
>> the last bit of strace up to the hang is:
>> 
>> pipe([3, 4])                            = 0
>> fcntl(3, F_DUPFD, 10)                   = 13
>> close(3)                                = 0
>> fcntl(4, F_DUPFD, 10)                   = 14
>> close(4)                                = 0
>> rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
>> clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f88402d89d0) = 26368
>> close(14)                               = 0
>> fcntl(13, F_GETFL)                      = 0 (flags O_RDONLY)
>> fstat(13, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
>> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f88402de000
>> lseek(13, 0, SEEK_CUR)                  = -1 ESPIPE (Illegal seek)
>> read(13, ######## hangs here for 10-30 sec then continues

> zsh isn't hanging; it's just waiting for the output of its forked child
> process (uname).  Try adding "-f" to your strace commandline, to follow
> child processes.
 
> -- 
> 	Dan Nelson
> 	dnelson@allantgroup.com

Re: zsh hangs loading init files

[Greg Klanderman]

hmm looks like users/14411

greg


>>>>> On January 6, 2012 Greg Klanderman <gak@klanderman.net> wrote:

> yes, thanks.

> looks like maybe HASH_DIRS logic was changed and is now stat()ing
> every potential executable it finds, whereas it used to only
> getdents() on all the dirs in your path.

> still haven't found the changeset.

> greg


>>>>> On January 5, 2012 Dan Nelson <dnelson@allantgroup.com> wrote:

>> In the last episode (Jan 05), Greg Klanderman said:
>>> 
>>> Hi all,
>>> 
>>> I'm in the process of transitioning my work computer from debian 5.0
>>> (lenny) to an Ubuntu variant that Google uses (Goobuntu) and having
>>> trouble with newer versions of zsh.  While loading my init files, zsh
>>> hangs several times for 10-30 sec.  This is not happening on 4.3.10
>>> which came with the Goobuntu distribution, or a 4.3.10 which I built
>>> from source, but is occurring with 4.3.15 and a cvs checkout in
>>> between 4.3.11 and 4.3.12 which I built.  I do not see the problem on
>>> my old debian box.
>>> 
>>> By putting in some print statements, the first hang seems to occur
>>> at a command substitution
>>> 
>>> | case "$(uname -s)" in
>>> |   ...
>>> 
>>> the last bit of strace up to the hang is:
>>> 
>>> pipe([3, 4])                            = 0
>>> fcntl(3, F_DUPFD, 10)                   = 13
>>> close(3)                                = 0
>>> fcntl(4, F_DUPFD, 10)                   = 14
>>> close(4)                                = 0
>>> rt_sigprocmask(SIG_BLOCK, [CHLD], [CHLD], 8) = 0
>>> clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f88402d89d0) = 26368
>>> close(14)                               = 0
>>> fcntl(13, F_GETFL)                      = 0 (flags O_RDONLY)
>>> fstat(13, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
>>> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f88402de000
>>> lseek(13, 0, SEEK_CUR)                  = -1 ESPIPE (Illegal seek)
>>> read(13, ######## hangs here for 10-30 sec then continues

>> zsh isn't hanging; it's just waiting for the output of its forked child
>> process (uname).  Try adding "-f" to your strace commandline, to follow
>> child processes.
 
>> -- 
>> Dan Nelson
>> dnelson@allantgroup.com

Re: zsh hangs loading init files

[Mikael Magnusson]

Please don't top post.

On 7 January 2012 02:12, Greg Klanderman <gak@klanderman.net> wrote:
>
> yes, thanks.
>
> looks like maybe HASH_DIRS logic was changed and is now stat()ing
> every potential executable it finds, whereas it used to only
> getdents() on all the dirs in your path.
>
> still haven't found the changeset.

I suspect this is the one, http://www.zsh.org/mla/users/2009/msg00786.html

commit e85349fbf793f18211d9280ca80ec8911e05c708
Author:     Peter Stephenson <pws@users.sourceforge.net>
AuthorDate: Mon Sep 21 09:22:20 2009 +0000

    users/14411: Src/hashtable.c: only hash stat-able executable regular
    files as commands
---
 ChangeLog       |    7 ++++++-
 Src/hashtable.c |   43 +++++++++++++++++++++++++++++++++++++------
 2 files changed, 43 insertions(+), 7 deletions(-)

diff --git a/ChangeLog b/ChangeLog
index d51b6d1..4a477ad 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -1,3 +1,8 @@
+2009-09-21  Peter Stephenson  <pws@csr.com>
+
+       * users/14411: Src/hashtable.c: only hash stat-able executable
+       regular files in the command table.
+

-- 
Mikael Magnusson

Re: zsh hangs loading init files

[Greg Klanderman]

>>>>> On January 6, 2012 Mikael Magnusson <mikachu@gmail.com> wrote:

> I suspect this is the one, http://www.zsh.org/mla/users/2009/msg00786.html

> +2009-09-21  Peter Stephenson  <pws@csr.com>
> +
> +       * users/14411: Src/hashtable.c: only hash stat-able executable
> +       regular files in the command table.
> +

You probably haven't gotten my followup to my followup yet.

Adding "setopt nohashdirs" gets me past the $(uname -s) quickly, but
then later, accessing $commands[foo] still causes it to go stat()
every file under every element of my path.  Which is causing the 10-30
second hang.

Greg

Re: zsh hangs loading init files

[Mikael Magnusson]

On 7 January 2012 02:36, Greg Klanderman <gak@klanderman.net> wrote:
>>>>>> On January 6, 2012 Mikael Magnusson <mikachu@gmail.com> wrote:
>
>> I suspect this is the one, http://www.zsh.org/mla/users/2009/msg00786.html
>
>> +2009-09-21  Peter Stephenson  <pws@csr.com>
>> +
>> +       * users/14411: Src/hashtable.c: only hash stat-able executable
>> +       regular files in the command table.
>> +
>
> You probably haven't gotten my followup to my followup yet.
>
> Adding "setopt nohashdirs" gets me past the $(uname -s) quickly, but
> then later, accessing $commands[foo] still causes it to go stat()
> every file under every element of my path.  Which is causing the 10-30
> second hang.

There is no option to disable the stat()ing while filling the hash,
and you do want to fill the hash, or you won't be able to complete any
command names.
% setopt no${^options[(I)hash*]}
% hash -r
% ls #to put one command in the hash
% l<tab>
---- external command
ls


Incidentally, the manpage says
       HASH_DIRS <D>
              Whenever a command name is hashed, hash the directory
containing it,
              as well as all directories that occur earlier in the path.  Has no
              effect if neither HASH_CMDS nor CORRECT is set.

However, setting hashdirs still causes the hash to be filled when both
hashcmds and correct are unset.

% setopt no${^options[(I)hash*]}
% hash -r
% ls
% hash | wc -l
1
% setopt hashdirs
% ls
% hash | wc -l
3480

-- 
Mikael Magnusson

Re: zsh hangs loading init files

[Bart Schaefer]

On Jan 6,  8:27pm, Greg Klanderman wrote:
}
} hmm looks like users/14411

In that message, PWS pondered:

> I'm not sure why we don't check that commands are executables, was there
> ever a reason?

Apparently the answer is "Yeah, if you've got 10,000 executables or
a remote filesystem in your path, it takes a really long time to stat
them all."

On Jan 6,  8:36pm, Greg Klanderman wrote:
}
} Adding "setopt nohashdirs" gets me past the $(uname -s) quickly, but
} then later, accessing $commands[foo] still causes it to go stat()
} every file under every element of my path.

The zsh/parameter module uses the HASH_LIST_ALL option to determine
whether to fill the hash table when referencing $commands.  I'm not
sure that's documented anywhere ... this is also true for spelling
correction, so the part of the HASH_CMDS doc that refers to CORRECT
is at least incomplete.

Another way to cause the table to be filled is to use "whence -m".

On Jan 7,  2:56am, Mikael Magnusson wrote:
}
} There is no option to disable the stat()ing while filling the hash

Perhaps what should have been done is to stat them when reading them
back, but that would have required some state bits in the table.  An
option would be the next best thing.

} Incidentally, the manpage says
}        HASH_DIRS <D>
}               Whenever a command name is hashed, hash the directory
}               containing it, as well as all directories that occur
}               earlier in the path. Has no effect if neither HASH_CMDS
}               nor CORRECT is set.
} 
} However, setting hashdirs still causes the hash to be filled when both
} hashcmds and correct are unset.

Hrm.  I'm not able to reproduce that from "zsh -f".

torch% setopt no${^options[(I)hash*]}
torch% hash -r
torch% ls
...
torch% print $#commands
0
torch% setopt hashdirs
torch% ls
...
torch% print $#commands
0
torch% 

Re: zsh hangs loading init files

[Peter Stephenson]

On Fri, 06 Jan 2012 23:17:00 -0800
Bart Schaefer <schaefer@brasslantern.com> wrote:
> On Jan 6,  8:27pm, Greg Klanderman wrote:
> } hmm looks like users/14411
> 
> In that message, PWS pondered:
> 
> > I'm not sure why we don't check that commands are executables, was there
> > ever a reason?
> 
> Apparently the answer is "Yeah, if you've got 10,000 executables or
> a remote filesystem in your path, it takes a really long time to stat
> them all."

Not sure it's even worth making this an option, since it's going to have
to be off by default to avoid surprises and few people are going to
bother to turn it on, and mosth PATH directories only contain
executables anyway, but it's not much extra code.

Index: Doc/Zsh/options.yo
===================================================================
RCS file: /cvsroot/zsh/zsh/Doc/Zsh/options.yo,v
retrieving revision 1.105
diff -p -u -r1.105 options.yo
--- Doc/Zsh/options.yo	28 Dec 2011 03:20:19 -0000	1.105
+++ Doc/Zsh/options.yo	7 Jan 2012 20:14:37 -0000
@@ -1155,6 +1155,20 @@ Whenever a command name is hashed, hash 
 as well as all directories that occur earlier in the path.
 Has no effect if neither tt(HASH_CMDS) nor tt(CORRECT) is set.
 )
+pindex(HASH_EXECUTABLES_ONLY)
+pindex(NO_HASH_EXECUTABLES_ONLY)
+pindex(HASHEXECUTABLESONLY)
+pindex(NOHASHEXECUTABLESONLY)
+cindex(hashing, of executables)
+cindex(executables, hashing)
+item(tt(HASH_EXECUTABLES_ONLY))(
+When hashing commands because of tt(HASH_COMMANDS), check that the
+file to be hashed is actually an executable.  This option
+is unset by default as if the path contains a large number of commands,
+or consists of many remote files, the additional tests can take
+a long time.  Trial and error is needed to show if this option is
+beneficial.
+)
 pindex(MAIL_WARNING)
 pindex(NO_MAIL_WARNING)
 pindex(MAILWARNING)
Index: Src/hashtable.c
===================================================================
RCS file: /cvsroot/zsh/zsh/Src/hashtable.c,v
retrieving revision 1.34
diff -p -u -r1.34 hashtable.c
--- Src/hashtable.c	9 May 2011 10:38:02 -0000	1.34
+++ Src/hashtable.c	7 Jan 2012 20:14:37 -0000
@@ -663,8 +663,9 @@ hashdir(char **dirp)
 		 * This is the same test as for the glob qualifier for
 		 * executable plain files.
 		 */
-		if (stat(pathbuf, &statbuf) == 0 &&
-		    S_ISREG(statbuf.st_mode) && (statbuf.st_mode & S_IXUGO))
+		if (unset(HASHEXECUTABLESONLY) ||
+		    (stat(pathbuf, &statbuf) == 0 &&
+		     S_ISREG(statbuf.st_mode) && (statbuf.st_mode & S_IXUGO)))
 		    add = 1;
 	    }
 	    if (add) {
Index: Src/options.c
===================================================================
RCS file: /cvsroot/zsh/zsh/Src/options.c,v
retrieving revision 1.58
diff -p -u -r1.58 options.c
--- Src/options.c	8 Dec 2011 19:42:07 -0000	1.58
+++ Src/options.c	7 Jan 2012 20:14:37 -0000
@@ -140,6 +140,7 @@ static struct optname optns[] = {
 {{NULL, "globsubst",	      OPT_EMULATE|OPT_NONZSH},	 GLOBSUBST},
 {{NULL, "hashcmds",	      OPT_ALL},			 HASHCMDS},
 {{NULL, "hashdirs",	      OPT_ALL},			 HASHDIRS},
+{{NULL, "hashexecutablesonly", 0},                       HASHEXECUTABLESONLY},
 {{NULL, "hashlistall",	      OPT_ALL},			 HASHLISTALL},
 {{NULL, "histallowclobber",   0},			 HISTALLOWCLOBBER},
 {{NULL, "histbeep",	      OPT_ALL},			 HISTBEEP},
Index: Src/params.c
===================================================================
RCS file: /cvsroot/zsh/zsh/Src/params.c,v
retrieving revision 1.176
diff -p -u -r1.176 params.c
--- Src/params.c	4 Jan 2012 22:35:55 -0000	1.176
+++ Src/params.c	7 Jan 2012 20:14:38 -0000
@@ -3780,9 +3780,6 @@ static struct localename {
 #ifdef LC_TIME
     {"LC_TIME", LC_TIME},
 #endif
-#ifdef LC_ALL
-    {"LC_ALL", LC_ALL},
-#endif
     {NULL, 0}
 };
 
@@ -3791,6 +3788,10 @@ static void
 setlang(char *x)
 {
     struct localename *ln;
+    char *x2;
+
+    if ((x2 = getsparam("LC_ALL")) && *x2)
+	return;
 
     /*
      * Set the global locale to the value passed, but override
Index: Src/zsh.h
===================================================================
RCS file: /cvsroot/zsh/zsh/Src/zsh.h,v
retrieving revision 1.178
diff -p -u -r1.178 zsh.h
--- Src/zsh.h	8 Dec 2011 19:42:07 -0000	1.178
+++ Src/zsh.h	7 Jan 2012 20:14:38 -0000
@@ -1986,6 +1986,7 @@ enum {
     GLOBSUBST,
     HASHCMDS,
     HASHDIRS,
+    HASHEXECUTABLESONLY,
     HASHLISTALL,
     HISTALLOWCLOBBER,
     HISTBEEP,

-- 
Peter Stephenson <p.w.stephenson@ntlworld.com>
Web page now at http://homepage.ntlworld.com/p.w.stephenson/

Re: zsh hangs loading init files

[Greg Klanderman]

thank you Peter, Bart, and Mikael!

greg