Re: Where to start debugging zle recursive-edit? / Ctrl-C

[Sebastian Gniazdowski <sgniazdowski@xxxxxxxxx>]

On 30 September 2016 at 13:28, Sebastian Gniazdowski
<sgniazdowski@xxxxxxxxx> wrote:
> But I've catched another thing. After Ctrl-C in .recursiveedit the
> timeouts at select() in raw_getbyte() stop occuring. Here is simple

I've investigated this further. There is calc_timeout() called in the
select-loop:

  case ZTM_MAX:
      /*...*/
      calc_timeout(&tmout, do_keytmout);
      // MY DEBUG
      FILE *_F = fopen("/tmp/recursive.txt", "a+");
      fprintf( _F, "^^^ LOOP-CALLED calc_timeout: tmout.tp == %d\n", tmout.tp );
      fclose(_F);
      break;


The calc_timeout is capable of setting tmout.tp to ZTM_NONE. I have 3
debug prints:

-- tmoutp->tp <- ZTM_NONE / calc_timeout( do_keytmout: 0 ), keytimeout: 4
== CALC_TIMEOUT() one more chance (timedfns)
-- CALC_TIMEOUT() !tfnode break

Code of the last debug message is below:

            LinkNode tfnode = firstnode(timedfns);
            Timedfn tfdat;
            time_t diff, exp100ths;

            if (!tfnode) {
                // MY DEBUG
                FILE *_F = fopen("/tmp/recursive.txt", "a+");
                fprintf( _F, "-- CALC_TIMEOUT() !tfnode break\n",
tmoutp->exp100ths );
                fclose(_F);
                break;
            }

So, the linked list doesn't have any elements, and calc_timeout()
exits with ZTM_NONE instead of ZTM_FUNC like it does all the time (so
normally it executes further the for(;;) there and overwrites initial
ZTM_NONE with ZTM_FUNC). This is after the lucky Ctrl-C. Wonder why no
ZTM_KEY? Also, believe me, I occured 2 spontaneous stopping of
timeouting right after shell started. Tried to catch this on asciinema
but no luck. It looket like – few timeouts occured and then they
stopped. Didn't have precise debug prints then..

Best regards,
Sebastian Gniazdowski

diff --git a/Src/Zle/zle_main.c b/Src/Zle/zle_main.c
index 9a83d41..1f993fe 100644
--- a/Src/Zle/zle_main.c
+++ b/Src/Zle/zle_main.c
@@ -450,47 +450,82 @@ static void
 calc_timeout(struct ztmout *tmoutp, long do_keytmout)
 {
     if (do_keytmout && (keytimeout > 0 || do_keytmout < 0)) {
 	if (do_keytmout < 0)
 	    tmoutp->exp100ths = (time_t)-do_keytmout;
 	else if (keytimeout > ZMAXTIMEOUT * 100 /* 24 days for a keypress???? */)
 	    tmoutp->exp100ths = ZMAXTIMEOUT * 100;
 	else
 	    tmoutp->exp100ths = keytimeout;
 	tmoutp->tp = ZTM_KEY;
-    } else
+        // MY DEBUG
+        FILE *_F = fopen("/tmp/recursive.txt", "a+");
+        fprintf( _F, "-- tmoutp->tp <- ZTM_KEY (%d) / calc_timeout() zle_main.c\n", tmoutp->exp100ths );
+        fclose(_F);
+    } else {
+        // MY DEBUG
+        FILE *_F = fopen("/tmp/recursive.txt", "a+");
+        fprintf( _F, "-- tmoutp->tp <- ZTM_NONE / calc_timeout( do_keytmout: %d ), keytimeout: %d / zle_main.c\n", do_keytmout );
+        fclose(_F);
+
 	tmoutp->tp = ZTM_NONE;
+    }
 
     if (timedfns) {
+        // MY DEBUG
+        FILE *_F = fopen("/tmp/recursive.txt", "a+");
+        fprintf( _F, "== CALC_TIMEOUT() one more chance (timedfns)\n", tmoutp->exp100ths );
+        fclose(_F);
 	for (;;) {
 	    LinkNode tfnode = firstnode(timedfns);
 	    Timedfn tfdat;
 	    time_t diff, exp100ths;
 
-	    if (!tfnode)
+	    if (!tfnode) {
+                // MY DEBUG
+                FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                fprintf( _F, "-- CALC_TIMEOUT() !tfnode break\n", tmoutp->exp100ths );
+                fclose(_F);
 		break;
+            }
 
 	    tfdat = (Timedfn)getdata(tfnode);
 	    diff = tfdat->when - time(NULL);
+
+            // MY DEBUG
+            FILE *_F = fopen("/tmp/recursive.txt", "a+");
+            fprintf( _F, "-- CALC_TIMEOUT() tfnode TRUE no break >> DIFF=%d <<\n", diff );
+            fclose(_F);
+
 	    if (diff < 0) {
 		/* Already due; call it and rescan. */
 		tfdat->func();
 		continue;
 	    }
 
 	    if (diff > ZMAXTIMEOUT) {
+                // MY DEBUG
+                FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                fprintf( _F, "-- CALC_TIMEOUT() %d > %d ZTM_MAX(%d)\n", diff, ZMAXTIMEOUT, ZTM_MAX );
+                fclose(_F);
+
 		tmoutp->exp100ths = ZMAXTIMEOUT * 100;
 		tmoutp->tp = ZTM_MAX;
 	    } else if (diff > 0) {
 		exp100ths = diff * 100;
 		if (tmoutp->tp != ZTM_KEY ||
 		    exp100ths < tmoutp->exp100ths) {
+                    // MY DEBUG
+                    FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                    fprintf( _F, "-- CALC_TIMEOUT() %d != %d || %d < %d ZTM_FUNC(%d)\n", tmoutp->tp, ZTM_KEY, exp100ths, tmoutp->exp100ths, ZTM_FUNC );
+                    fclose(_F);
+
 		    tmoutp->exp100ths = exp100ths;
 		    tmoutp->tp = ZTM_FUNC;
 		}
 	    }
 	    break;
 	}
 	/* In case we called a function which messed up the display... */
 	if (resetneeded)
 	    zrefresh();
     }
@@ -508,20 +543,24 @@ raw_getbyte(long do_keytmout, char *cptr)
     struct ttyinfo ti;
 #endif
 #ifndef HAVE_POLL
 # ifdef HAVE_SELECT
     fd_set foofd, errfd;
     FD_ZERO(&errfd);
 # endif
 #endif
 
     calc_timeout(&tmout, do_keytmout);
+    // MY DEBUG
+    FILE *_F = fopen("/tmp/recursive.txt", "a+");
+    fprintf( _F, "-- INIT tmout.tp(%d) ZTM_NONE(%d) ZTM_KEY(%d) / BEGIN RAW_GETBYTE() zle_main.c\n", tmout.tp, ZTM_NONE, ZTM_KEY );
+    fclose(_F);
 
     /*
      * Handle timeouts and watched fd's.  If a watched fd or a function
      * timeout triggers we restart any key timeout.  This is likely to
      * be harmless: the combination is extremely rare and a function
      * is likely to occupy the user for a little while anyway.  We used
      * to make timeouts take precedence, but we can't now that the
      * timeouts may be external, so we may have both a permanent watched
      * fd and a long-term timeout.
      */
@@ -600,43 +639,78 @@ raw_getbyte(long do_keytmout, char *cptr)
 		    if (fd > fdmax)
 			fdmax = fd;
 		}
 	    }
 	    FD_ZERO(&errfd);
 
 	    if (tmout.tp != ZTM_NONE) {
 		expire_tv.tv_sec = tmout.exp100ths / 100;
 		expire_tv.tv_usec = (tmout.exp100ths % 100) * 10000L;
 		tvptr = &expire_tv;
+
+                // MY DEBUG
+                FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                fprintf( _F, "\n-- tmoutp != ZTM_NONE / raw_getbyte() zle_main.c\n" );
+                fclose(_F);
 	    }
-	    else
+	    else {
+                // MY DEBUG
+                FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                fprintf( _F, "\n-- FINAL (STOP) tmoutp == ZTM_NONE / raw_getbyte() zle_main.c\n" );
+                fclose(_F);
+
 		tvptr = NULL;
+            }
 
 	    winch_unblock();
 	    selret = select(fdmax+1, (SELECT_ARG_2_T) & foofd,
 			    NULL, NULL, tvptr);
 	    winch_block();
 # endif
 	    /*
 	     * Make sure a user interrupt gets passed on straight away.
 	     */
-	    if (selret < 0 && (errflag || retflag || breaks || exit_pending))
+	    if (selret < 0 && (errflag || retflag || breaks || exit_pending)) {
+                // MY DEBUG
+                FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                fprintf( _F, "-- Doing break / zle_main.c: errflag: %d, retflag: %d, breaks: %d, exit_pending: %d\n",
+                            errflag, retflag, breaks, exit_pending );
+                fclose(_F);
 		break;
+            } else {
+                // MY DEBUG
+                FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                fprintf( _F, "-- NOT doing break / zle_main.c: errflag: %d, retflag: %d, breaks: %d, exit_pending: %d\n",
+                            errflag, retflag, breaks, exit_pending );
+                fclose(_F);
+            }
+
 	    /*
 	     * Try to avoid errors on our special fd's from
 	     * messing up reads from the terminal.  Try first
 	     * with all fds, then try unsetting the special ones.
 	     */
 	    if (selret < 0 && !errtry) {
+                // MY DEBUG
+                FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                fprintf( _F, "-- Trying again !errtry / zle_main.c\n" );
+                fclose(_F);
+
 		errtry = 1;
 		continue;
-	    }
+	    } else {
+                // MY DEBUG
+                FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                fprintf( _F, "--  Passed !errtry(errtry:%d) / zle_main.c\n", errtry );
+                fclose(_F);
+            }
+
 	    if (selret == 0) {
 		/*
 		 * Nothing ready and no error, so we timed out.
 		 */
 		switch (tmout.tp) {
 		case ZTM_NONE:
 		    /* keeps compiler happy if not debugging */
 #ifdef DEBUG
 		    dputs("BUG: timeout fired with no timeout set.");
 #endif
@@ -669,20 +743,24 @@ raw_getbyte(long do_keytmout, char *cptr)
 		case ZTM_MAX:
 		    /*
 		     * Reached the limit of our range, but not the
 		     * actual timeout; recalculate the timeout.
 		     * We're cheating with the key timeout here:
 		     * if one clashed with a function timeout we
 		     * reconsider the key timeout from scratch.
 		     * The effect of this is microscopic.
 		     */
 		    calc_timeout(&tmout, do_keytmout);
+                    // MY DEBUG
+                    FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                    fprintf( _F, "^^^ LOOP-CALLED calc_timeout: tmout.tp == %d / zle_main.c\n", tmout.tp );
+                    fclose(_F);
 		    break;
 		}
 		/*
 		 * If we handled the timeout successfully,
 		 * carry on.
 		 */
 		if (selret == 0)
 		    continue;
 	    }
 	    /* If error or unhandled timeout, give up. */
@@ -888,22 +966,36 @@ getbyte(long do_keytmout, int *timeout)
 		   the counter (icnt) so that this happens 20 times and than
 		   the shell gives up (yes, this is a bit dirty...). */
 		if ((zlereadflags & ZLRF_IGNOREEOF) && icnt++ < 20)
 		    continue;
 		stopmsg = 1;
 		zexit(1, 0);
 	    }
 	    icnt = 0;
 	    if (errno == EINTR) {
 		die = 0;
+                static int counter = 0;
+
+                // MY DEBUG
+                FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                fprintf( _F, "-- Got EINTR %d\n", ++counter );
+                fclose(_F);
+
 		if (!errflag && !retflag && !breaks && !exit_pending)
+                {
+                    // MY DEBUG
+                    FILE *_F = fopen("/tmp/recursive.txt", "a+");
+                    fprintf( _F, "-- Continuing despite EINTR / zle_main.c: errflag: %d, retflag: %d, breaks: %d, exit_pending: %d\n",
+                                errflag, retflag, breaks, exit_pending );
+                    fclose(_F);
 		    continue;
+                }
 		errflag &= ~ERRFLAG_ERROR;
 		breaks = obreaks;
 		errno = old_errno;
 		return lastchar = EOF;
 	    } else if (errno == EWOULDBLOCK) {
 		fcntl(0, F_SETFL, 0);
 	    } else if (errno == EIO && !die) {
 		ret = opts[MONITOR];
 		opts[MONITOR] = 1;
 		attachtty(mypgrp);
@@ -1115,20 +1207,24 @@ zlecore(void)
 		if (eofsent)
 		    break;
 	    }
 	    handleprefixes();
 	    /* for vi mode, make sure the cursor isn't somewhere illegal */
 	    if (invicmdmode() && zlecs > findbol() &&
 		(zlecs == zlell || zleline[zlecs] == ZWC('\n')))
 		DECCS();
 	    handleundo();
 	} else {
+            // MY DEBUG
+            FILE *_F = fopen("/tmp/recursive.txt", "a+");
+            fprintf( _F, "-- Setting error in zlecore.c\n" );
+            fclose(_F);
 	    errflag |= ERRFLAG_ERROR;
 	    break;
 	}
 
 	redrawhook();
 #ifdef HAVE_POLL
 	if (baud && !(lastcmd & ZLE_MENUCMP)) {
 	    struct pollfd pfd;
 	    int to = cost * costmult / 1000; /* milliseconds */