100,000 calls to rt_sigprocmask for a single <Tab>?

100,000 calls to rt_sigprocmask for a single <Tab>?

[Helmut Jarausch]

Hi,

on one of my machines ZSH is incredibly slow for <tab> completion.

In a directory with a single executable 'hg_upd' and a single  
subdirectory

./hg<tab>

takes more than 20 seconds. An strace shows that zsh executes nearly  
100,000
calls to rt_sigprocmask  like


mmap(NULL, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1,  
0) = 0x7ff4da23f000

then 2602 times

rt_sigprocmask(SIG_UNBLOCK, [WINCH], [CHLD WINCH], 8) = 0
rt_sigprocmask(SIG_BLOCK, [WINCH], [CHLD], 8) = 0

and this pattern about 20 times.

The whole strace log has 111,036 lines for just one entry of <tab>

What's wrong with my machine/installation?

I'm using  zsh-5.0.2-dev-0 (GIT version) on my Gentoo system,
which is nearly "bleeding edge".

This problem is not knew, I've been just too lazy to run zsh under  
strace.

Many thanks for a hint,
Helmut.

P.S. On a different but very similar machine this doesn't occur.

Re: 100,000 calls to rt_sigprocmask for a single <Tab>?

[Bart Schaefer]

On Oct 21, 12:29pm, Helmut Jarausch wrote:
}
} ./hg<tab>
} 
} takes more than 20 seconds. An strace shows that zsh executes nearly  
} 100,000 calls to rt_sigprocmask

Zsh started fiddling with the WINCH signal pretty recently, May 2013.
System calls were getting interrupted by things like window managers
that move and resize windows automatically (probably for "zoom" visual
effects when popping open the terminal app) combined with terminal
emulators that start the shell before the window is fully opened.

It's a fairly nasty problem; you want the shell to respond relatively
quickly to the window size changing for visual feedback, but most of
the code has to keep the signal blocked so system calls aren't borked.
We adopted the strategy of unblocking the signal whenever the shell may
be blocked for some other reason (usually, input) and then blocking it
again immediately.

Given your description of the strace, the most likely bit of code to be
executing is input.c:shingetline() -- it's the only place where you'd
see unblock/block pairs without another system call (select or poll or
read) in between [because it's wrapped around fgetc() which buffers the
input so there needn't be a system call every time], and in that close
proximity to a memory allocation, and in a tight loop.

BUT ... that implies that a lot of input (50k or so, if it's 2600-some
unblock/block pairs repeated 20 times) is being consumed (e.g., by the
"source" or "." command).  Is it always 2602 unblock/block repeats or
does it vary?

Still, as a first check, you could try the patch below, which should
cut down the number of block/unblock pairs or at least reverse the
order you see them (i.e., the SIG_BLOCK should preceed SIG_UNBLOCK
in most of the repetitions).

If this does fix it, your next task would be to figure out why the
shingetline() call is happening during that particular completion.


diff --git a/Src/input.c b/Src/input.c
index 9bd9663..4ac7e6e 100644
--- a/Src/input.c
+++ b/Src/input.c
@@ -142,14 +142,14 @@ shingetline(void)
     char *p;
 
     p = buf;
+    winch_unblock();
     for (;;) {
-	winch_unblock();
 	do {
 	    errno = 0;
 	    c = fgetc(bshin);
 	} while (c < 0 && errno == EINTR);
-	winch_block();
 	if (c < 0 || c == '\n') {
+	    winch_block();
 	    if (c == '\n')
 		*p++ = '\n';
 	    if (p > buf) {
@@ -165,11 +165,13 @@ shingetline(void)
 	} else
 	    *p++ = c;
 	if (p >= buf + BUFSIZ - 1) {
+	    winch_block();
 	    line = zrealloc(line, ll + (p - buf) + 1);
 	    memcpy(line + ll, buf, p - buf);
 	    ll += p - buf;
 	    line[ll] = '\0';
 	    p = buf;
+	    winch_unblock();
 	}
     }
 }